OOM error : Direct memory buffer

ds_algos · August 1, 2019, 11:36am

Hi,

I am using firehose to aggregate by daily(aggregated for the whole day) data and it always fails while BUILDING the segment.

2019-07-31T11:06:59,942 INFO [appenderator_merge_0] org.apache.druid.segment.CompressedPools - Allocating new littleEndByteBuf[81,818]

2019-07-31T11:06:59,943 INFO [appenderator_merge_0] org.apache.druid.segment.CompressedPools - Allocating new littleEndByteBuf[81,819]

2019-07-31T11:07:02,078 INFO [task-runner-0-priority-0] org.apache.druid.segment.realtime.appenderator.AppenderatorImpl - Shutting down…

2019-07-31T11:07:02,081 INFO [appenderator_persist_0] org.apache.druid.segment.realtime.appenderator.AppenderatorImpl - Removing sink for segment[HSS_Monthly_2019-06-01T00:00:00.000Z_2019-07-01T00:00:00.0

00Z_2019-07-31T10:52:17.507Z].

2019-07-31T11:07:02,102 ERROR [task-runner-0-priority-0] org.apache.druid.indexing.common.task.IndexTask - Encountered exception in BUILD_SEGMENTS.

java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.OutOfMemoryError: Direct buffer memory

.

Caused by: java.lang.OutOfMemoryError: Direct buffer memory

at java.nio.Bits.reserveMemory(Bits.java:694) ~[?:1.8.0_152]

at java.nio.DirectByteBuffer.(DirectByteBuffer.java:123) ~[?:1.8.0_152]

at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:311) ~[?:1.8.0_152]

at org.apache.druid.segment.CompressedPools$4.get(CompressedPools.java:105) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.CompressedPools$4.get(CompressedPools.java:98) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.collections.StupidPool.makeObjectWithHandler(StupidPool.java:116) ~[druid-common-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.collections.StupidPool.take(StupidPool.java:107) ~[druid-common-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.CompressedPools.getByteBuf(CompressedPools.java:113) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.data.DecompressingByteBufferObjectStrategy.fromByteBuffer(DecompressingByteBufferObjectStrategy.java:49) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.data.DecompressingByteBufferObjectStrategy.fromByteBuffer(DecompressingByteBufferObjectStrategy.java:28) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.data.GenericIndexed$BufferIndexed.bufferedIndexedGet(GenericIndexed.java:444) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.data.GenericIndexed$2.get(GenericIndexed.java:599) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.data.BlockLayoutColumnarDoublesSupplier$BlockLayoutColumnarDoubles.loadBuffer(BlockLayoutColumnarDoublesSupplier.java:109) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.data.BlockLayoutColumnarDoublesSupplier$1.get(BlockLayoutColumnarDoublesSupplier.java:65) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.data.ColumnarDoubles$1HistoricalDoubleColumnSelector.getDouble(ColumnarDoubles.java:58) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.selector.settable.SettableDoubleColumnValueSelector.setValueFrom(SettableDoubleColumnValueSelector.java:36) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.QueryableIndexIndexableAdapter$RowIteratorImpl.setRowPointerValues(QueryableIndexIndexableAdapter.java:323) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.QueryableIndexIndexableAdapter$RowIteratorImpl.moveToNext(QueryableIndexIndexableAdapter.java:299) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.ForwardingRowIterator.moveToNext(ForwardingRowIterator.java:62) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.MergingRowIterator.lambda$new$0(MergingRowIterator.java:84) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at java.util.stream.IntPipeline$9$1.accept(IntPipeline.java:343) ~[?:1.8.0_152]

at java.util.stream.Streams$RangeIntSpliterator.forEachRemaining(Streams.java:110) ~[?:1.8.0_152]

at java.util.Spliterator$OfInt.forEachRemaining(Spliterator.java:693) ~[?:1.8.0_152]

at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481) ~[?:1.8.0_152]

at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471) ~[?:1.8.0_152]

at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:545) ~[?:1.8.0_152]

at java.util.stream.AbstractPipeline.evaluateToArrayNode(AbstractPipeline.java:260) ~[?:1.8.0_152]

at java.util.stream.ReferencePipeline.toArray(ReferencePipeline.java:438) ~[?:1.8.0_152]

at org.apache.druid.segment.MergingRowIterator.(MergingRowIterator.java:92) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.RowCombiningTimeAndDimsIterator.(RowCombiningTimeAndDimsIterator.java:108) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.IndexMergerV9.lambda$merge$2(IndexMergerV9.java:909) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.IndexMergerV9.makeMergedTimeAndDimsIterator(IndexMergerV9.java:1031) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.IndexMergerV9.makeIndexFiles(IndexMergerV9.java:179) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

at org.apache.druid.segment.IndexMergerV9.merge(IndexMergerV9.java:914) ~[druid-processing-0.13.0-incubating.jar:0.13.0-incubating]

I have provided -Xms=3g Xmx=8g MaxDirectMemorySize=15g memory configuraraion.

What is going wrong ?? why it tries to create too many DictionaryMergeIterator object and buffers ??

How can i modify my configuration to reduce the amount of memory being used while merging the indexes .

Thanks,

Ming_F · August 1, 2019, 6:53pm

Hi , can you show us the runtime.properties for your middlemanager service?

Thanks

Rommel_Garcia · August 1, 2019, 7:16pm

This is the formula for providing the Direct Memory Buffer = druid.processing.buffer.sizeBytes * (druid.processing.numMergeBuffers + druid.processing.numThreads + 1)
Depending on your query, the actual utilization might be higher but this is the general guide.

Rommel Garcia

ds_algos · August 2, 2019, 7:24am

Hi Rommel,

Good to see you again, i met you at the druid summit 24/7

I see we have more than 1200+ columns in a single data source.

“context”:
{

“druid.indexer.fork.property.druid.indexer.runner.javaOpts”: “-server
-d64 -Xms3g -Xmx8g -XX:MaxDirectMemorySize=20g -XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/apps/eenpm/customized_druid/apache-druid-0.13.0-incubating/var/sv/HeapDump_HSS_Monthly.hprof
-XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps
-XX:+PrintGCDateStamps
-Xloggc:/apps/eenpm/customized_druid/apache-druid-0.13.0-incubating/var/sv/gc_%p.log
-XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=50M
-Duser.timezone=UTC -Dfile.encoding=UTF-8 -Djava.util.logging.manager=org.apache.logging.log4j.jul.LogManager”,

“druid.indexer.fork.property.druid.processing.numMergeBuffers”: 5,

“druid.indexer.fork.property.druid.processing.buffer.sizeBytes”:
134217728

}

**I am overriding it for a particular index task, **

here are the runtime.properties.

Number of tasks per middleManager

druid.worker.capacity=25

Task launch parameters

druid.indexer.runner.javaOpts=-server -d64 -Xms1g -Xmx5g -XX:MaxDirectMemorySize=8g -XX:+HeapDumpOnOutOfMemoryError -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:/apps/eenpm/customized_druid/apache-druid-0.13.0-incubating/var/sv/gc_%p.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=50M -Duser.timezone=UTC -Dfile.encoding=UTF-8 -Djava.util.logging.manager=org.apache.logging.log4j.jul.LogManager

druid.indexer.task.baseTaskDir=var/druid/task

druid.indexer.task.restoreTasksOnRestart=true

Processing threads and buffers

Hadoop indexing

druid.indexer.task.hadoopWorkingPath=var/druid/hadoop-tmp

druid.indexer.task.defaultHadoopCoordinates=[“org.apache.hadoop:hadoop-client:2.3.0”]

Peon properties

druid.indexer.fork.property.druid.processing.buffer.sizeBytes=268435456

druid.indexer.fork.property.druid.processing.numMergeBuffers=2

druid.indexer.fork.property.druid.processing.numThreads=10

Happy Learning.

ds_algos · August 2, 2019, 8:11am

And why in the logs i see it as **memory[1,037,959,168], maxMemory[5,189,795,840], even though the my memory configuration is **-Xms2g -Xmx8g -XX:MaxDirectMemorySize=15g .

2019-08-02T07:31:56,365 INFO [main] org.apache.druid.cli.CliPeon - Starting up with processors[32], memory[1,037,959,168], maxMemory[5,189,795,840].

2019-08-02T07:31:56,365 INFO [main] org.apache.druid.cli.CliPeon - * awt.toolkit: sun.awt.X11.XToolkit

2019-08-02T07:31:56,365 INFO [main] org.apache.druid.cli.CliPeon - * druid.extensions.hadoopDependenciesDir: hadoop-dependencies

2019-08-02T07:31:56,365 INFO [main] org.apache.druid.cli.CliPeon - * druid.extensions.loadList: [“druid-kafka-eight”, “druid-histogram”, “druid-datasketches”, “druid-lookups-cached-global”, "mysql-metadat

a-storage", “druid-kafka-indexing-service”, “druid-hdfs-storage”]

2019-08-02T07:31:56,366 INFO [main] org.apache.druid.cli.CliPeon - * druid.host: 10.54.146.33

2019-08-02T07:31:56,366 INFO [main] org.apache.druid.cli.CliPeon - * druid.indexer.fork.property.druid.processing.buffer.sizeBytes: 268435456

2019-08-02T07:31:56,366 INFO [main] org.apache.druid.cli.CliPeon - * druid.indexer.fork.property.druid.processing.numMergeBuffers: 2

2019-08-02T07:31:56,366 INFO [main] org.apache.druid.cli.CliPeon - * druid.indexer.fork.property.druid.processing.numThreads: 10

2019-08-02T07:31:56,366 INFO [main] org.apache.druid.cli.CliPeon - * druid.indexer.logs.directory: var/druid/indexing-logs

2019-08-02T07:31:56,366 INFO [main] org.apache.druid.cli.CliPeon - * druid.indexer.logs.type: file

2019-08-02T07:31:56,366 INFO [main] org.apache.druid.cli.CliPeon - * druid.indexer.runner.javaOpts: -server -d64 -Xms2g -Xmx8g -XX:MaxDirectMemorySize=15g -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=

/apps/eenpm/customized_druid/apache-druid-0.13.0-incubating/var/sv/HeapDump_%p.hprof -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:/apps/eenpm/customiz

ed_druid/apache-druid-0.13.0-incubating/var/sv/gc_%p.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=50M -Duser.timezone=UTC -Dfile.encoding=UTF-8 -Djava.util.logging.manager=org

.apache.logging.log4j.jul.LogManager

Because even if i am changing the MaxDirectMemorySize, the number of merge buffers it could create with 10g and 15g configuration are the same.

Doubting if it really overrides the memory configurations or not.

2019-08-02T07:59:21,429 INFO [appenderator_merge_0] org.apache.druid.segment.CompressedPools - Allocating new littleEndByteBuf[109,595]

Please let me know if there is a bug logged or some memory leak.

Happy Learning.

ds_algos · August 7, 2019, 1:08pm

Looks like “context” object parameters are not being used to override peon level properties.

here you go

why the following error?? why its considering 8G as max direct memory which is provided in runtime.properties?? why not the parameters defined in “context” object.

Not enough direct memory. Please adjust -XX:MaxDirectMemorySize, druid.processing.buffer.sizeBytes, druid.processing.numThreads, or druid.processing.numMergeBuffers: maxDirectMemory[8,589,934,592], memoryNeeded[10,500,000,000] = druid.processing.buffer.sizeBytes[750,000,000] * (druid.processing.numMergeBuffers[3] + druid.processing.numThreads[10] + 1)

even if my jvm parameters are

2019-08-07T06:45:31,762 INFO [main] org.apache.druid.cli.CliPeon - * druid.indexer.runner.javaOpts: -server -Xms3g -Xmx8g -XX:MaxDirectMemorySize=15g -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/apps

/eenpm/customized_druid/apache-druid-0.13.0-incubating/var/sv/HeapDump.hprof -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:/apps/eenpm/customized_druid

/apache-druid-0.13.0-incubating/var/sv/gc_%p.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=50M -Duser.timezone=UTC -Dfile.encoding=UTF-8 -Djava.util.logging.manager=org.apache.

logging.log4j.jul.LogManager