You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@druid.apache.org by GitBox <gi...@apache.org> on 2019/01/16 13:26:14 UTC
[GitHub] Stephan3555 opened a new issue #6871: maxBytesInMemory not working
Stephan3555 opened a new issue #6871: maxBytesInMemory not working
URL: https://github.com/apache/incubator-druid/issues/6871
Hello guys,
we are upgrading our Druid Cluster from 0.12.3 to 0.13.0 and wanted to use the new maxBytesInMemory feature. But its seems not to work properly.
**Ingestion-spec:**
```
{
"type":"kafka",
"dataSchema":{
"dataSource":"de.id.cms.pageview-geoip-raw_test",
"parser":{
"type":"avro_stream",
"avroBytesDecoder":{
"type":"schema_registry",
"url":"http://schema.confluent-tools:8081"
},
"parseSpec":{
"format":"avro",
"flattenSpec":{
"useFieldDiscovery":"true",
"fields":[
"url",
"onlineId",
"channel",
"category",
"clientId",
"uid",
"newUser",
"timestamp",
"userAgent",
"group",
"pageType",
"os",
"deviceType",
"browser",
"browserType",
"headline",
"seoHeadline",
"documentLabel",
"referrer",
"referrerDomain",
"regional",
"authors",
{
"type":"path",
"name":"clientIP",
"expr":"$.clientIP"
},
{
"type":"path",
"name":"city",
"expr":"$.city"
},
{
"type":"path",
"name":"location",
"expr":"$.location"
},
"accuracyRadius",
{
"type":"path",
"name":"postalCode",
"expr":"$.postalCode"
},
"devicePixelRatio"
]
},
"timestampSpec":{
"column":"timestamp",
"format":"auto"
},
"dimensionsSpec":{
"dimensions":[
"url",
"onlineId",
"channel",
"category",
"clientId",
"uid",
"newUser",
"timestamp",
"userAgent",
"group",
"pageType",
"os",
"deviceType",
"browser",
"browserType",
"headline",
"seoHeadline",
"documentLabel",
"referrer",
"referrerDomain",
"regional",
"authors",
"clientIP",
"city",
"location",
"accuracyRadius",
"postalCode",
"devicePixelRatio"
]
}
}
},
"metricsSpec":[
{
"type":"count",
"name":"count"
},
{
"type":"thetaSketch",
"name":"uid_sketch",
"fieldName":"uid",
"size":16384,
"shouldFinalize":true,
"isInputThetaSketch":false,
"errorBoundsStdDev":null
}
],
"granularitySpec":{
"type":"uniform",
"segmentGranularity":"DAY",
"queryGranularity":"MINUTE",
"rollup":true,
"intervals":null
},
"transformSpec":{
"filter":null,
"transforms":[
]
}
},
"tuningConfig":{
"type":"kafka",
"maxBytesInMemory":1073741824,
"maxRowsPerSegment":5000000,
"maxTotalRows":null,
"intermediatePersistPeriod":"PT30M",
"maxPendingPersists":0,
"indexSpec":{
"bitmap":{
"type":"concise"
},
"dimensionCompression":"lz4",
"metricCompression":"lz4",
"longEncoding":"longs"
},
"buildV9Directly":true,
"reportParseExceptions":false,
"handoffConditionTimeout":0,
"resetOffsetAutomatically":true,
"segmentWriteOutMediumFactory":null,
"workerThreads":null,
"chatThreads":null,
"chatRetries":8,
"httpTimeout":"PT10S",
"shutdownTimeout":"PT80S",
"offsetFetchPeriod":"PT30S",
"intermediateHandoffPeriod":"P2147483647D",
"logParseExceptions":true,
"maxParseExceptions":2147483647,
"maxSavedParseExceptions":0
},
"ioConfig":{
"topic":"de.id.cms.pageview-geoip",
"replicas":1,
"taskCount":3,
"taskDuration":"PT1800S",
"consumerProperties":{
"bootstrap.servers":"kafka.confluent-kafka:9092"
},
"startDelay":"PT5S",
"period":"PT30S",
"useEarliestOffset":true,
"completionTimeout":"PT14400S",
"lateMessageRejectionPeriod":null,
"earlyMessageRejectionPeriod":null,
"skipOffsetGaps":true
},
"context":null,
"suspended":false
}
```
I set mayBytesInMemory to 1073741824 (=1GB).
**MiddleManager runtime.properties:**
```
# General settings
druid.service=druid/middleManager
druid.port=8091
# MiddleManager-specific settings
druid.worker.capacity=6
# Resources for peons
druid.indexer.task.baseTaskDir=var/druid/task
druid.indexer.task.restoreTasksOnRestart=true
druid.indexer.runner.javaOpts=-server -Xmx3g -XX:+UseG1GC -Duser.timezone=UTC -Dfile.encoding=UTF-8 -Djava.io.tmpdir=var/druid/task/tmp -Djava.util.logging.manager=org.apache.logging.log4j.jul.LogManager -Dorg.jboss.logging.provider=slf4j -Dnet.spy.log.LoggerImpl=net.spy.memcached.compat.log.SLF4JLogger -Dlog4j.shutdownCallbackRegistry=org.apache.druid.common.config.Log4jShutdown -Dlog4j.shutdownHookEnabled=true -Daws.region=eu-central-1 -XX:MaxGCPauseMillis=100 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime
# Peon Properties
druid.indexer.fork.property.druid.processing.buffer.sizeBytes=536870912
druid.indexer.fork.property.druid.processing.numThreads=2
#Monitoring
druid.monitoring.monitors=["org.apache.druid.java.util.metrics.JvmMonitor"]
```
In the Task logs beneath you can see that the persist happens after ~4000 rows. The smoosh file that is generated is only 539468 bytes (= 526.82422KB = 0.514477 MB). The GC logs tells me that there is almost no memory used:
```
[Eden: 123.0M(123.0M)->0.0B(133.0M) Survivors: 10.0M->4096.0K Heap: 312.8M(2660.0M)->187.3M(2743.0M)]
```
Snippet of one of the persists from the task with GC logs enabled to see the memory usage:
```
55.729: Application time: 2.0002503 seconds
55.729: Total time for which application threads were stopped: 0.0004492 seconds, Stopping threads took: 0.0000673 seconds
56.729: Application time: 1.0001427 seconds
56.730: Total time for which application threads were stopped: 0.0004427 seconds, Stopping threads took: 0.0000649 seconds
57.316: Application time: 0.5868024 seconds
57.317: Total time for which application threads were stopped: 0.0004205 seconds, Stopping threads took: 0.0000722 seconds
57.333: Application time: 0.0161511 seconds
57.334: [GC pause (G1 Evacuation Pause) (young), 0.0712134 secs]
[Parallel Time: 63.2 ms, GC Workers: 1]
[GC Worker Start (ms): 57334.0]
[Ext Root Scanning (ms): 6.7]
[Update RS (ms): 10.4]
[Processed Buffers: 73]
[Scan RS (ms): 8.7]
[Code Root Scanning (ms): 0.2]
[Object Copy (ms): 37.0]
[Termination (ms): 0.0]
[Termination Attempts: 1]
[GC Worker Other (ms): 0.0]
[GC Worker Total (ms): 63.1]
[GC Worker End (ms): 57397.0]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.3 ms]
[Clear CT: 0.3 ms]
[Other: 7.4 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.4 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.2 ms]
[Humongous Register: 0.2 ms]
[Humongous Reclaim: 0.5 ms]
[Free CSet: 0.8 ms]
[Eden: 123.0M(123.0M)->0.0B(133.0M) Survivors: 10.0M->4096.0K Heap: 312.8M(2660.0M)->187.3M(2743.0M)]
[Times: user=0.06 sys=0.02, real=0.07 secs]
57.405: Total time for which application threads were stopped: 0.0721021 seconds, Stopping threads took: 0.0000707 seconds
57.479: Application time: 0.0738574 seconds
57.480: Total time for which application threads were stopped: 0.0006307 seconds, Stopping threads took: 0.0000618 seconds
57.480: Application time: 0.0000531 seconds
57.480: Total time for which application threads were stopped: 0.0002748 seconds, Stopping threads took: 0.0000248 seconds
57.488: Application time: 0.0080521 seconds
57.489: Total time for which application threads were stopped: 0.0004471 seconds, Stopping threads took: 0.0000999 seconds
57.490: Application time: 0.0010580 seconds
57.490: Total time for which application threads were stopped: 0.0003472 seconds, Stopping threads took: 0.0000738 seconds
57.505: Application time: 0.0150652 seconds
57.506: Total time for which application threads were stopped: 0.0005885 seconds, Stopping threads took: 0.0000676 seconds
57.506: Application time: 0.0001339 seconds
57.506: Total time for which application threads were stopped: 0.0003994 seconds, Stopping threads took: 0.0000898 seconds
58.506: Application time: 1.0001120 seconds
58.507: Total time for which application threads were stopped: 0.0006655 seconds, Stopping threads took: 0.0000671 seconds
59.507: Application time: 1.0001475 seconds
59.508: Total time for which application threads were stopped: 0.0004066 seconds, Stopping threads took: 0.0000745 seconds
66.509: Application time: 7.0010076 seconds
66.509: Total time for which application threads were stopped: 0.0005189 seconds, Stopping threads took: 0.0000723 seconds
68.509: Application time: 2.0002949 seconds
68.510: Total time for which application threads were stopped: 0.0004554 seconds, Stopping threads took: 0.0000702 seconds
69.510: Application time: 1.0001534 seconds
69.510: Total time for which application threads were stopped: 0.0003965 seconds, Stopping threads took: 0.0000722 seconds
74.511: Application time: 5.0010242 seconds
74.641: Total time for which application threads were stopped: 0.1299278 seconds, Stopping threads took: 0.1295629 seconds
78.642: Application time: 4.0006512 seconds
78.643: Total time for which application threads were stopped: 0.0005637 seconds, Stopping threads took: 0.0000769 seconds
79.643: Application time: 1.0000980 seconds
79.643: Total time for which application threads were stopped: 0.0006788 seconds, Stopping threads took: 0.0001616 seconds
80.644: Application time: 1.0001498 seconds
80.644: Total time for which application threads were stopped: 0.0005040 seconds, Stopping threads took: 0.0000719 seconds
81.644: Application time: 1.0001452 seconds
81.645: Total time for which application threads were stopped: 0.0004674 seconds, Stopping threads took: 0.0000762 seconds
85.645: Application time: 4.0005832 seconds
85.646: Total time for which application threads were stopped: 0.0004010 seconds, Stopping threads took: 0.0000680 seconds
88.646: Application time: 3.0004925 seconds
88.647: Total time for which application threads were stopped: 0.0010882 seconds, Stopping threads took: 0.0000743 seconds
2019-01-16T12:03:46,782 INFO [task-runner-0-priority-0] org.apache.druid.segment.realtime.appenderator.AppenderatorImpl - Submitting persist runnable for dataSource[de.id.cms.pageview-geoip-raw_test]
2019-01-16T12:03:46,782 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.realtime.appenderator.AppenderatorImpl - Segment[de.id.cms.pageview-geoip-raw_test_2019-01-16T00:00:00.000Z_2019-01-17T00:00:00.000Z_2019-01-16T00:00:15.880Z_76], persisting Hydrant[FireHydrant{, queryable=de.id.cms.pageview-geoip-raw_test_2019-01-16T00:00:00.000Z_2019-01-17T00:00:00.000Z_2019-01-16T00:00:15.880Z_76, count=18}]
2019-01-16T12:03:46,785 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.IndexMergerV9 - Starting persist for interval[2019-01-16T00:00:00.000Z/2019-01-17T00:00:00.000Z], rows[4,066]
2019-01-16T12:03:46,801 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.IndexMergerV9 - Using SegmentWriteOutMediumFactory[TmpFileSegmentWriteOutMediumFactory]
2019-01-16T12:03:46,801 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.IndexMergerV9 - Completed version.bin in 0 millis.
2019-01-16T12:03:46,801 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.IndexMergerV9 - Completed factory.json in 0 millis
2019-01-16T12:03:46,802 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[url] conversions with cardinality[1] in 1 millis.
2019-01-16T12:03:46,802 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[onlineId] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:46,803 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[channel] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:46,804 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[category] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:46,804 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[clientId] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:46,902 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[uid] conversions with cardinality[4,066] in 98 millis.
2019-01-16T12:03:46,903 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[newUser] conversions with cardinality[1] in 1 millis.
92.651: Application time: 4.0032330 seconds
92.651: Total time for which application threads were stopped: 0.0005177 seconds, Stopping threads took: 0.0001504 seconds
2019-01-16T12:03:47,000 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[timestamp] conversions with cardinality[3,746] in 96 millis.
2019-01-16T12:03:47,000 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[userAgent] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,001 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[group] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,001 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[pageType] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,002 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[os] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,002 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[deviceType] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,003 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[browser] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,004 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[browserType] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,004 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[headline] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,004 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[seoHeadline] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,005 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[documentLabel] conversions with cardinality[0] in 0 millis.
2019-01-16T12:03:47,005 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[referrer] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,006 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[referrerDomain] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,007 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[regional] conversions with cardinality[1] in 1 millis.
2019-01-16T12:03:47,007 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[authors] conversions with cardinality[0] in 0 millis.
2019-01-16T12:03:47,008 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[clientIP] conversions with cardinality[1] in 1 millis.
2019-01-16T12:03:47,008 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[city] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,009 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[location] conversions with cardinality[1] in 1 millis.
2019-01-16T12:03:47,009 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[accuracyRadius] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,010 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[postalCode] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,010 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[devicePixelRatio] conversions with cardinality[1] in 0 millis.
2019-01-16T12:03:47,011 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.IndexMergerV9 - Completed dim conversions in 210 millis.
2019-01-16T12:03:47,134 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.IndexMergerV9 - completed walk through of 4,066 rows in 122 millis.
2019-01-16T12:03:47,136 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.IndexMergerV9 - Completed time column in 0 millis.
2019-01-16T12:03:47,136 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.IndexMergerV9 - Completed metric column[count] in 0 millis.
2019-01-16T12:03:47,136 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.IndexMergerV9 - Completed metric column[uid_sketch] in 0 millis.
2019-01-16T12:03:47,137 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.IndexMergerV9 - Completed metric columns in 0 millis.
2019-01-16T12:03:47,137 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[url] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,138 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[onlineId] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,139 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[channel] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,140 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[category] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,141 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[clientId] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,233 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[uid] inverted with cardinality[4,066] in 92 millis.
2019-01-16T12:03:47,547 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[newUser] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,629 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[timestamp] inverted with cardinality[3,746] in 81 millis.
2019-01-16T12:03:47,631 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[userAgent] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,632 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[group] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,633 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[pageType] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,634 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[os] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,635 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[deviceType] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,636 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[browser] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,637 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[browserType] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,638 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[headline] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,639 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[seoHeadline] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,639 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[documentLabel] inverted with cardinality[0] in 0 millis.
2019-01-16T12:03:47,640 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[referrer] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,641 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[referrerDomain] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,641 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[regional] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,642 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[authors] inverted with cardinality[0] in 0 millis.
2019-01-16T12:03:47,643 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[clientIP] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,644 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[city] inverted with cardinality[1] in 0 millis.
2019-01-16T12:03:47,645 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[location] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,646 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[accuracyRadius] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,647 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[postalCode] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,648 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.StringDimensionMergerV9 - Completed dim[devicePixelRatio] inverted with cardinality[1] in 1 millis.
2019-01-16T12:03:47,649 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.IndexMergerV9 - Completed index.drd in 1 millis.
2019-01-16T12:03:47,649 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.java.util.common.io.smoosh.FileSmoosher - Created smoosh file [/druid/var/druid/task/index_kafka_de.id.cms.pageview-geoip-raw_test_1bf2ca875c68755_fjieolod/work/persist/de.id.cms.pageview-geoip-raw_test_2019-01-16T00:00:00.000Z_2019-01-17T00:00:00.000Z_2019-01-16T00:00:15.880Z_76/18/00000.smoosh] of size [539468] bytes.
2019-01-16T12:03:47,661 INFO [de.id.cms.pageview-geoip-raw_test-incremental-persist] org.apache.druid.segment.realtime.appenderator.AppenderatorImpl - Committing metadata[AppenderatorDriverMetadata{segments={index_kafka_de.id.cms.pageview-geoip-raw_test_1bf2ca875c68755_0=[SegmentWithState{segmentIdentifier=de.id.cms.pageview-geoip-raw_test_2019-01-16T00:00:00.000Z_2019-01-17T00:00:00.000Z_2019-01-16T00:00:15.880Z_76, state=APPENDING}]}, lastSegmentIds={index_kafka_de.id.cms.pageview-geoip-raw_test_1bf2ca875c68755_0=de.id.cms.pageview-geoip-raw_test_2019-01-16T00:00:00.000Z_2019-01-17T00:00:00.000Z_2019-01-16T00:00:15.880Z_76}, callerMetadata={nextPartitions=KafkaPartitions{topic='de.id.cms.pageview-geoip', partitionOffsetMap={2=1134559, 5=1131501, 8=1134452, 11=1140739, 14=1134486, 17=1130916, 20=1134563, 23=1130919}}}}] for sinks[de.id.cms.pageview-geoip-raw_test_2019-01-16T00:00:00.000Z_2019-01-17T00:00:00.000Z_2019-01-16T00:00:15.880Z_76:19].
93.370: Application time: 0.7192836 seconds
93.372: Total time for which application threads were stopped: 0.0017559 seconds, Stopping threads took: 0.0002357 seconds
2019-01-16T12:03:47,664 INFO [appenderator_persist_0] org.apache.druid.indexing.kafka.IncrementalPublishingKafkaIndexTaskRunner - Persist completed with metadata [AppenderatorDriverMetadata{segments={index_kafka_de.id.cms.pageview-geoip-raw_test_1bf2ca875c68755_0=[SegmentWithState{segmentIdentifier=de.id.cms.pageview-geoip-raw_test_2019-01-16T00:00:00.000Z_2019-01-17T00:00:00.000Z_2019-01-16T00:00:15.880Z_76, state=APPENDING}]}, lastSegmentIds={index_kafka_de.id.cms.pageview-geoip-raw_test_1bf2ca875c68755_0=de.id.cms.pageview-geoip-raw_test_2019-01-16T00:00:00.000Z_2019-01-17T00:00:00.000Z_2019-01-16T00:00:15.880Z_76}, callerMetadata={nextPartitions=KafkaPartitions{topic='de.id.cms.pageview-geoip', partitionOffsetMap={2=1134559, 5=1131501, 8=1134452, 11=1140739, 14=1134486, 17=1130916, 20=1134563, 23=1130919}}}}]
96.372: Application time: 3.0003263 seconds
96.373: Total time for which application threads were stopped: 0.0004519 seconds, Stopping threads took: 0.0000700 seconds
99.373: Application time: 3.0004380 seconds
99.374: Total time for which application threads were stopped: 0.0003995 seconds, Stopping threads took: 0.0000713 seconds
105.198: Application time: 5.8244671 seconds
105.199: [GC pause (G1 Evacuation Pause) (young), 0.0403941 secs]
[Parallel Time: 38.2 ms, GC Workers: 1]
[GC Worker Start (ms): 105199.3]
[Ext Root Scanning (ms): 6.2]
[Update RS (ms): 10.5]
[Processed Buffers: 83]
[Scan RS (ms): 6.0]
[Code Root Scanning (ms): 0.4]
[Object Copy (ms): 14.9]
[Termination (ms): 0.0]
[Termination Attempts: 1]
[GC Worker Other (ms): 0.0]
[GC Worker Total (ms): 38.0]
[GC Worker End (ms): 105237.3]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.2 ms]
[Other: 2.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.7 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.1 ms]
[Humongous Register: 0.2 ms]
[Humongous Reclaim: 0.1 ms]
[Free CSet: 0.3 ms]
[Eden: 133.0M(133.0M)->0.0B(192.0M) Survivors: 4096.0K->4096.0K Heap: 320.3M(2743.0M)->187.8M(2743.0M)]
[Times: user=0.04 sys=0.00, real=0.04 secs]
```
On the other Hand if I disable the maxBytesInMemory feature by setting it to '-1', let the intermediatePersistPeriod be 'PT30M' and let the maxRowsInMemory be the default '1000000'. It lets me generate much larger smoosh files, without significant increasing the Memory size.
I put the log output in a file because of its size. You can find it attached (task_logs_for_disabled_maxBytesInMemory.log)
The persist happened when the intermediatePersistPeriod kicked in after 30 min, which is also the taskDuration. The smoosh file is in total 27991861 bytes (= 27,991861 MB).
**So in conclusion the maxBytesInMemory limit seems not to work for my Kafka ingestion.**
Am I missing something or is this a bug in the implementation?
[task_logs_for_disabled_maxBytesInMemory.log](https://github.com/apache/incubator-druid/files/2764329/task_logs_for_disabled_maxBytesInMemory.log)
Best regards,
Stephan
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@druid.apache.org
For additional commands, e-mail: commits-help@druid.apache.org