Middle manager task keep running because of cannot hand off segments to historical node

Hi ,

I have a task index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0 that is still in running status, while today is 11/10 and other tasks are up-to-date:

{"status":{"id":"index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0","status":"RUNNING","duration":-1},"task":"index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0"}

And druid_segments table lacks of the hourly segment "MiddletiersBillingProd_2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z_2015-11-06T13:00:12.828Z". This task cannot hand off data to historical nodes.

Do you have any suggestion to fix it?

Paste some logs of this task:

2015-11-06T13:00:12,511 INFO [task-runner-0] io.druid.segment.realtime.plumber.RealtimePlumber - Creating plumber using rejectionPolicy[io.druid.segment.realtime.plumber.NoopRejectionPolicyFactory$1@4629cf3b]
2015-11-06T13:00:12,516 INFO [task-runner-0] io.druid.segment.realtime.plumber.RealtimePlumber - Expect to run at [2015-11-06T14:55:00.000Z]
2015-11-06T13:00:12,517 INFO [task-runner-0] io.druid.segment.realtime.plumber.RealtimePlumber - Starting merge and push.
2015-11-06T13:00:12,518 INFO [task-runner-0] io.druid.segment.realtime.plumber.RealtimePlumber - Found [0] segments. Attempting to hand off segments that start before [1970-01-01T00:00:00.000Z].
2015-11-06T13:00:12,518 INFO [task-runner-0] io.druid.segment.realtime.plumber.RealtimePlumber - Found [0] sinks to persist and merge
2015-11-06T13:00:12,519 INFO [task-runner-0] io.druid.segment.realtime.firehose.EventReceiverFirehoseFactory - Connecting firehose: druid:firehose:MiddletiersBillingProd-13-0000-0000
2015-11-06T13:00:12,520 INFO [task-runner-0] io.druid.segment.realtime.firehose.EventReceiverFirehoseFactory - Found chathandler of class[io.druid.segment.realtime.firehose.ServiceAnnouncingChatHandlerProvider]
2015-11-06T13:00:12,520 INFO [task-runner-0] io.druid.segment.realtime.firehose.ServiceAnnouncingChatHandlerProvider - Registering Eventhandler[druid:firehose:MiddletiersBillingProd-13-0000-0000]
2015-11-06T13:00:12,522 INFO [task-runner-0] io.druid.curator.discovery.CuratorServiceAnnouncer - Announcing service[DruidNode{serviceName=‘druid:firehose:MiddletiersBillingProd-13-0000-0000’, host=‘hh-miui-ad-preview01.bj’, port=8104}]
2015-11-06T13:00:12,570 INFO [task-runner-0] io.druid.segment.realtime.firehose.ServiceAnnouncingChatHandlerProvider - Registering Eventhandler[MiddletiersBillingProd-13-0000-0000]
2015-11-06T13:00:12,571 INFO [task-runner-0] io.druid.curator.discovery.CuratorServiceAnnouncer - Announcing service[DruidNode{serviceName=‘MiddletiersBillingProd-13-0000-0000’, host=‘hh-miui-ad-preview01.bj’, port=8104}]
2015-11-06T13:00:12,580 INFO [task-runner-0] io.druid.data.input.FirehoseFactory - Firehose created, will shut down at: 2015-11-06T23:00:00.000+08:00
2015-11-06T13:00:12,826 INFO [task-runner-0] io.druid.indexing.common.actions.RemoteTaskActionClient - Performing action for task[index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0]: LockAcquireAction{interval=2015-11-06T13:00:00.000Z/2015-11-06T14:00:00.000Z}
2015-11-06T13:00:12,829 INFO [task-runner-0] io.druid.indexing.common.actions.RemoteTaskActionClient - Submitting action for task[index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0] to overlord[http://lg-miui-data-stat02.bj:8753/druid/indexer/v1/action]: LockAcquireAction{interval=2015-11-06T13:00:00.000Z/2015-11-06T14:00:00.000Z}
2015-11-06T13:00:12,851 INFO [task-runner-0] io.druid.indexing.common.actions.RemoteTaskActionClient - Performing action for task[index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0]: LockAcquireAction{interval=2015-11-06T13:00:00.000Z/2015-11-06T14:00:00.000Z}
2015-11-06T13:00:12,853 INFO [task-runner-0] io.druid.indexing.common.actions.RemoteTaskActionClient - Submitting action for task[index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0] to overlord[http://lg-miui-data-stat02.bj:8753/druid/indexer/v1/action]: LockAcquireAction{interval=2015-11-06T13:00:00.000Z/2015-11-06T14:00:00.000Z}
2015-11-06T13:00:12,870 INFO [task-runner-0] io.druid.server.coordination.BatchDataSegmentAnnouncer - Announcing segment[MiddletiersBillingProd_2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z_2015-11-06T13:00:12.828Z] at path[/druid/prod/segments/hh-miui-ad-preview01.bj:8104/hh-miui-ad-preview01.bj:8104_realtime__default_tier_2015-11-06T13:00:12.868Z_d8732a5e811d48f1bc8143f8c3c5642b0]
9.306: [GC pause (young), 0.04105500 secs]
[Parallel Time: 31.8 ms]
[GC Worker Start (ms): 9306.3 9306.4 9306.4 9306.4 9306.4 9306.4 9306.4 9306.4
Avg: 9306.4, Min: 9306.3, Max: 9306.4, Diff: 0.1]
[Ext Root Scanning (ms): 4.4 7.6 7.6 5.0 4.6 4.7 3.7 3.9
Avg: 5.2, Min: 3.7, Max: 7.6, Diff: 3.9]
[Update RS (ms): 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.1
Avg: 0.0, Min: 0.0, Max: 0.1, Diff: 0.1]
[Processed Buffers : 0 0 0 0 0 0 0 36
Sum: 36, Avg: 4, Min: 0, Max: 36, Diff: 36]
[Scan RS (ms): 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.4
Avg: 0.1, Min: 0.0, Max: 0.4, Diff: 0.4]
[Object Copy (ms): 23.7 23.9 20.6 23.2 23.5 23.4 24.4 23.7
Avg: 23.3, Min: 20.6, Max: 24.4, Diff: 3.8]
[Termination (ms): 3.4 0.0 3.3 3.4 3.4 3.4 3.4 3.4
Avg: 2.9, Min: 0.0, Max: 3.4, Diff: 3.4]
[Termination Attempts : 2 1 1 1 1 2 2 2
Sum: 12, Avg: 1, Min: 1, Max: 2, Diff: 1]
[GC Worker End (ms): 9337.9 9337.9 9337.9 9337.9 9337.9 9337.9 9337.9 9337.9
Avg: 9337.9, Min: 9337.9, Max: 9337.9, Diff: 0.0]
[GC Worker (ms): 31.5 31.5 31.5 31.5 31.5 31.5 31.5 31.5
Avg: 31.5, Min: 31.5, Max: 31.5, Diff: 0.1]
[GC Worker Other (ms): 0.3 0.3 0.3 0.3 0.3 0.3 0.3 0.3
Avg: 0.3, Min: 0.3, Max: 0.3, Diff: 0.1]
[Clear CT: 0.1 ms]
[Other: 9.1 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 8.2 ms]
[Ref Enq: 0.1 ms]
[Free CSet: 0.6 ms]
[Eden: 391M(391M)->0B(67M) Survivors: 10M->41M Heap: 400M(502M)->40M(502M)]
[Times: user=0.21 sys=0.02, real=0.04 secs]
9.627: [GC pause (young), 0.06439600 secs]
[Parallel Time: 63.2 ms]
[GC Worker Start (ms): 9626.6 9626.6 9626.6 9626.6 9626.6 9636.6 9636.7 9642.5
Avg: 9631.1, Min: 9626.6, Max: 9642.5, Diff: 15.9]
[Ext Root Scanning (ms): 4.4 4.6 3.0 4.5 4.6 0.0 0.0 0.0
Avg: 2.6, Min: 0.0, Max: 4.6, Diff: 4.6]
[Update RS (ms): 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0
Avg: 0.0, Min: 0.0, Max: 0.0, Diff: 0.0]
[Processed Buffers : 0 0 5 0 0 0 0 0
Sum: 5, Avg: 0, Min: 0, Max: 5, Diff: 5]
[Scan RS (ms): 0.0 0.0 0.1 0.0 0.0 0.0 0.0 0.0
Avg: 0.0, Min: 0.0, Max: 0.1, Diff: 0.1]
[Object Copy (ms): 48.2 47.9 49.5 48.1 47.9 42.5 42.5 36.6
Avg: 45.4, Min: 36.6, Max: 49.5, Diff: 12.9]
[Termination (ms): 0.1 0.1 0.1 0.0 0.1 10.2 0.0 0.1
Avg: 1.3, Min: 0.0, Max: 10.2, Diff: 10.2]
[Termination Attempts : 2 1 1 1 1 1 1 1
Sum: 9, Avg: 1, Min: 1, Max: 2, Diff: 1]
[GC Worker End (ms): 9679.2 9679.2 9679.2 9679.2 9679.2 9689.3 9679.2 9679.2
Avg: 9680.5, Min: 9679.2, Max: 9689.3, Diff: 10.1]
[GC Worker (ms): 52.7 52.7 52.7 52.6 52.6 52.7 42.6 36.7
Avg: 49.4, Min: 36.7, Max: 52.7, Diff: 15.9]
[GC Worker Other (ms): 10.5 10.5 10.5 10.5 10.5 10.5 20.6 26.4
Avg: 13.8, Min: 10.5, Max: 26.4, Diff: 15.9]
[Clear CT: 0.1 ms]
[Other: 1.1 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.4 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.3 ms]
[Eden: 67M(67M)->0B(86M) Survivors: 41M->14M Heap: 107M(502M)->45M(502M)]
[Times: user=0.26 sys=0.00, real=0.07 secs]
9.979: [GC pause (young), 0.03597300 secs]
[Parallel Time: 30.8 ms]
[GC Worker Start (ms): 9979.5 9979.5 9979.5 9979.5 9979.5 9989.8 9989.8 9989.9
Avg: 9983.4, Min: 9979.5, Max: 9989.9, Diff: 10.4]
[Ext Root Scanning (ms): 4.5 3.7 4.1 4.0 3.3 0.0 0.0 0.0
Avg: 2.5, Min: 0.0, Max: 4.5, Diff: 4.5]
[Update RS (ms): 0.6 1.1 0.9 1.0 1.4 0.0 0.0 0.0
Avg: 0.6, Min: 0.0, Max: 1.4, Diff: 1.4]
[Processed Buffers : 6 6 4 5 11 0 0 0
Sum: 32, Avg: 4, Min: 0, Max: 11, Diff: 11]
[Scan RS (ms): 0.1 0.1 0.1 0.1 0.2 0.0 0.0 0.0
Avg: 0.1, Min: 0.0, Max: 0.2, Diff: 0.2]
[Object Copy (ms): 25.2 25.4 25.1 25.1 25.4 20.0 19.9 20.0
Avg: 23.3, Min: 19.9, Max: 25.4, Diff: 5.5]
[Termination (ms): 0.1 0.1 0.1 0.1 0.1 0.0 0.1 0.0
Avg: 0.1, Min: 0.0, Max: 0.1, Diff: 0.1]
[Termination Attempts : 1 5 7 4 6 1 3 1
Sum: 28, Avg: 3, Min: 1, Max: 7, Diff: 6]
[GC Worker End (ms): 10009.9 10009.9 10009.9 10009.9 10009.9 10009.9 10009.9 10009.9
Avg: 10009.9, Min: 10009.9, Max: 10009.9, Diff: 0.0]
[GC Worker (ms): 30.4 30.4 30.4 30.4 30.4 20.0 20.0 20.0
Avg: 26.5, Min: 20.0, Max: 30.4, Diff: 10.4]
[GC Worker Other (ms): 0.4 0.4 0.4 0.4 0.4 10.7 10.7 10.7
Avg: 4.3, Min: 0.4, Max: 10.7, Diff: 10.4]
[Clear CT: 0.1 ms]
[Other: 5.1 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 4.8 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.2 ms]
[Eden: 86M(86M)->0B(87M) Survivors: 14M->13M Heap: 131M(502M)->59M(502M)]
[Times: user=0.22 sys=0.00, real=0.03 secs]
10.149: [GC pause (young), 0.02962100 secs]
[Parallel Time: 28.8 ms]
[GC Worker Start (ms): 10149.5 10149.5 10149.5 10149.5 10149.6 10155.5 10155.5 10155.6
Avg: 10151.8, Min: 10149.5, Max: 10155.6, Diff: 6.0]
[Ext Root Scanning (ms): 3.4 3.0 3.1 3.7 3.4 0.0 0.0 0.0
Avg: 2.1, Min: 0.0, Max: 3.7, Diff: 3.7]
[Update RS (ms): 0.8 1.0 1.2 0.4 0.8 0.0 0.0 0.0
Avg: 0.5, Min: 0.0, Max: 1.2, Diff: 1.2]
[Processed Buffers : 4 7 5 1 12 0 0 0
Sum: 29, Avg: 3, Min: 0, Max: 12, Diff: 12]
[Scan RS (ms): 0.2 0.2 0.1 0.1 0.3 0.0 0.0 0.0
Avg: 0.1, Min: 0.0, Max: 0.3, Diff: 0.3]
[Object Copy (ms): 19.4 19.6 19.3 24.0 19.4 17.8 17.9 17.8
Avg: 19.4, Min: 17.8, Max: 24.0, Diff: 6.2]
[Termination (ms): 4.4 4.4 4.4 0.0 4.4 4.4 4.3 4.4
Avg: 3.9, Min: 0.0, Max: 4.4, Diff: 4.4]
[Termination Attempts : 1 1 1 1 1 1 1 1
Sum: 8, Avg: 1, Min: 1, Max: 1, Diff: 0]
[GC Worker End (ms): 10177.8 10177.8 10177.8 10177.8 10177.8 10177.8 10177.8 10177.8
Avg: 10177.8, Min: 10177.8, Max: 10177.8, Diff: 0.0]
[GC Worker (ms): 28.2 28.2 28.2 28.2 28.2 22.2 22.2 22.2
Avg: 26.0, Min: 22.2, Max: 28.2, Diff: 6.0]
[GC Worker Other (ms): 0.5 0.5 0.5 0.6 0.5 6.5 6.5 6.6
Avg: 2.8, Min: 0.5, Max: 6.6, Diff: 6.0]
[Clear CT: 0.1 ms]
[Other: 0.8 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.2 ms]
[Eden: 87M(87M)->0B(115M) Survivors: 13M->12M Heap: 146M(502M)->67M(502M)]
[Times: user=0.15 sys=0.01, real=0.03 secs]
2015-11-06T13:00:14,013 INFO [ServerInventoryView-0] io.druid.client.BatchServerInventoryView - Inventory Initialized
2015-11-06T13:00:14,024 INFO [ServerInventoryView-0] io.druid.curator.inventory.CuratorInventoryManager - Created new InventoryCacheListener for /druid/prod/segments/hh-miui-ad-preview01.bj:8104
2015-11-06T13:00:14,024 INFO [ServerInventoryView-0] io.druid.client.BatchServerInventoryView - New Server[DruidServerMetadata{name=‘hh-miui-ad-preview01.bj:8104’, host=‘hh-miui-ad-preview01.bj:8104’, maxSize=0, tier=’_default_tier’, type=‘realtime’, priority=‘0’}]
10.823: [GC pause (young), 0.01865200 secs]
[Parallel Time: 17.7 ms]
[GC Worker Start (ms): 10823.0 10823.0 10823.1 10823.1 10823.1 10823.1 10823.1 10833.7
Avg: 10824.4, Min: 10823.0, Max: 10833.7, Diff: 10.6]
[Ext Root Scanning (ms): 3.1 2.2 2.2 3.0 2.8 3.0 2.4 0.0
Avg: 2.3, Min: 0.0, Max: 3.1, Diff: 3.1]
[Update RS (ms): 0.6 1.5 1.6 0.6 0.8 0.6 1.3 0.0
Avg: 0.9, Min: 0.0, Max: 1.6, Diff: 1.6]
[Processed Buffers : 2 38 4 2 2 3 4 0
Sum: 55, Avg: 6, Min: 0, Max: 38, Diff: 38]
[Scan RS (ms): 0.4 0.5 0.5 0.4 0.4 0.4 0.5 0.0
Avg: 0.4, Min: 0.0, Max: 0.5, Diff: 0.5]
[Object Copy (ms): 13.1 11.1 11.1 11.3 11.2 11.2 11.1 4.7
Avg: 10.6, Min: 4.7, Max: 13.1, Diff: 8.4]
[Termination (ms): 0.0 1.9 1.9 1.9 1.9 1.9 1.9 1.9
Avg: 1.7, Min: 0.0, Max: 1.9, Diff: 1.9]
[Termination Attempts : 1 1 1 1 1 1 2 1
Sum: 9, Avg: 1, Min: 1, Max: 2, Diff: 1]
[GC Worker End (ms): 10840.3 10840.3 10840.3 10840.3 10840.3 10840.3 10840.3 10840.3
Avg: 10840.3, Min: 10840.3, Max: 10840.3, Diff: 0.0]
[GC Worker (ms): 17.2 17.3 17.2 17.2 17.2 17.2 17.2 6.6
Avg: 15.9, Min: 6.6, Max: 17.3, Diff: 10.6]
[GC Worker Other (ms): 0.5 0.4 0.5 0.5 0.5 0.5 0.5 11.1
Avg: 1.8, Min: 0.4, Max: 11.1, Diff: 10.6]
[Clear CT: 0.1 ms]
[Other: 0.8 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.5 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.2 ms]
[Eden: 88M(115M)->0B(171M) Survivors: 12M->7168K Heap: 155M(502M)->71M(502M)]
[Times: user=0.12 sys=0.00, real=0.02 secs]
11.728: [GC pause (young), 0.01902500 secs]
[Parallel Time: 18.2 ms]
[GC Worker Start (ms): 11728.3 11729.3 11729.3 11732.0 11732.0 11732.0 11738.8 11738.8
Avg: 11732.6, Min: 11728.3, Max: 11738.8, Diff: 10.5]
[Ext Root Scanning (ms): 4.6 3.8 3.7 2.0 1.1 2.0 0.0 0.0
Avg: 2.2, Min: 0.0, Max: 4.6, Diff: 4.6]
[Update RS (ms): 1.6 1.6 1.7 1.0 2.0 0.8 0.0 0.0
Avg: 1.1, Min: 0.0, Max: 2.0, Diff: 2.0]
[Processed Buffers : 8 21 12 2 4 11 0 0
Sum: 58, Avg: 7, Min: 0, Max: 21, Diff: 21]
[Scan RS (ms): 0.8 0.8 0.8 0.7 0.6 0.8 0.0 0.0
Avg: 0.6, Min: 0.0, Max: 0.8, Diff: 0.8]
[Object Copy (ms): 10.7 10.5 10.4 10.3 10.3 10.3 7.3 7.2
Avg: 9.6, Min: 7.2, Max: 10.7, Diff: 3.5]
[Termination (ms): 0.1 0.1 0.1 0.1 0.1 0.1 0.0 0.1
Avg: 0.1, Min: 0.0, Max: 0.1, Diff: 0.1]
[Termination Attempts : 44 34 34 45 1 30 5 31
Sum: 224, Avg: 28, Min: 1, Max: 45, Diff: 44]
[GC Worker End (ms): 11746.1 11746.1 11746.1 11746.1 11746.1 11746.1 11746.1 11746.1
Avg: 11746.1, Min: 11746.1, Max: 11746.1, Diff: 0.0]
[GC Worker (ms): 17.8 16.8 16.7 14.1 14.1 14.1 7.3 7.3
Avg: 13.5, Min: 7.3, Max: 17.8, Diff: 10.5]
[GC Worker Other (ms): 0.4 1.4 1.4 4.1 4.1 4.1 10.9 10.9
Avg: 4.7, Min: 0.4, Max: 10.9, Diff: 10.5]
[Clear CT: 0.2 ms]
[Other: 0.7 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.2 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.3 ms]
[Eden: 124M(171M)->0B(207M) Survivors: 7168K->14M Heap: 195M(502M)->78M(502M)]
[Times: user=0.11 sys=0.00, real=0.02 secs]
12.923: [GC pause (young), 0.04012900 secs]
[Parallel Time: 39.0 ms]
[GC Worker Start (ms): 12922.9 12922.9 12922.9 12922.9 12922.9 12923.0 12923.0 12928.4
Avg: 12923.6, Min: 12922.9, Max: 12928.4, Diff: 5.5]
[Ext Root Scanning (ms): 11.2 4.5 3.6 11.2 3.5 4.0 3.5 0.0
Avg: 5.2, Min: 0.0, Max: 11.2, Diff: 11.2]
[Update RS (ms): 0.0 1.6 7.9 0.0 10.5 1.9 5.9 0.9
Avg: 3.6, Min: 0.0, Max: 10.5, Diff: 10.5]
[Processed Buffers : 0 18 1 0 4 17 3 14
Sum: 57, Avg: 7, Min: 0, Max: 18, Diff: 18]
[Scan RS (ms): 0.0 1.8 0.0 0.0 0.0 1.8 0.0 1.9
Avg: 0.7, Min: 0.0, Max: 1.9, Diff: 1.9]
[Object Copy (ms): 27.3 28.7 25.1 25.6 22.6 28.9 27.3 28.5
Avg: 26.7, Min: 22.6, Max: 28.9, Diff: 6.3]
[Termination (ms): 0.0 1.9 1.9 1.8 1.9 1.9 1.9 1.8
Avg: 1.6, Min: 0.0, Max: 1.9, Diff: 1.9]
[Termination Attempts : 1 1 1 1 1 1 2 2
Sum: 10, Avg: 1, Min: 1, Max: 2, Diff: 1]
[GC Worker End (ms): 12961.4 12961.5 12961.4 12961.4 12961.4 12961.4 12961.4 12961.4
Avg: 12961.4, Min: 12961.4, Max: 12961.5, Diff: 0.0]
[GC Worker (ms): 38.6 38.6 38.5 38.5 38.5 38.5 38.5 33.0
Avg: 37.8, Min: 33.0, Max: 38.6, Diff: 5.5]
[GC Worker Other (ms): 0.4 0.4 0.5 0.5 0.5 0.5 0.5 6.0
Avg: 1.2, Min: 0.4, Max: 6.0, Diff: 5.5]
[Clear CT: 0.1 ms]
[Other: 1.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.5 ms]
[Eden: 182M(207M)->0B(226M) Survivors: 14M->21M Heap: 260M(502M)->91M(502M)]
[Times: user=0.17 sys=0.00, real=0.04 secs]
15.804: [GC pause (young), 0.03639600 secs]
[Parallel Time: 35.5 ms]
[GC Worker Start (ms): 15803.8 15803.8 15803.9 15803.9 15803.9 15803.9 15804.0 15810.9
Avg: 15804.8, Min: 15803.8, Max: 15810.9, Diff: 7.1]
[Ext Root Scanning (ms): 3.2 2.9 2.5 2.5 2.3 2.4 3.0 0.0
Avg: 2.4, Min: 0.0, Max: 3.2, Diff: 3.2]
[Update RS (ms): 0.7 0.7 1.2 1.4 1.8 1.6 0.6 0.0
Avg: 1.0, Min: 0.0, Max: 1.8, Diff: 1.8]
[Processed Buffers : 11 6 14 4 4 4 13 0
Sum: 56, Avg: 7, Min: 0, Max: 14, Diff: 14]
[Scan RS (ms): 1.4 1.5 1.4 1.4 1.2 1.3 1.5 0.0
Avg: 1.2, Min: 0.0, Max: 1.5, Diff: 1.5]
[Object Copy (ms): 28.0 28.2 29.9 28.1 28.0 28.0 28.0 26.2
Avg: 28.0, Min: 26.2, Max: 29.9, Diff: 3.7]
[Termination (ms): 1.8 1.8 0.0 1.7 1.8 1.8 1.8 1.8
Avg: 1.6, Min: 0.0, Max: 1.8, Diff: 1.8]
[Termination Attempts : 1 1 1 1 1 1 1 1
Sum: 8, Avg: 1, Min: 1, Max: 1, Diff: 0]
[GC Worker End (ms): 15839.0 15839.0 15839.0 15839.0 15839.0 15839.0 15839.0 15839.0
Avg: 15839.0, Min: 15839.0, Max: 15839.0, Diff: 0.0]
[GC Worker (ms): 35.1 35.1 35.1 35.1 35.1 35.1 35.0 28.1
Avg: 34.2, Min: 28.1, Max: 35.1, Diff: 7.0]
[GC Worker Other (ms): 0.3 0.4 0.4 0.4 0.4 0.4 0.5 7.4
Avg: 1.3, Min: 0.3, Max: 7.4, Diff: 7.0]
[Clear CT: 0.1 ms]
[Other: 0.8 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.2 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.3 ms]
[Eden: 166M(226M)->0B(308M) Survivors: 21M->11M Heap: 257M(502M)->101M(502M)]
[Times: user=0.21 sys=0.00, real=0.04 secs]
17.240: [GC pause (young), 0.03251700 secs]
[Parallel Time: 31.1 ms]
[GC Worker Start (ms): 17240.3 17240.3 17240.3 17240.3 17240.3 17247.3 17247.4 17247.4
Avg: 17243.0, Min: 17240.3, Max: 17247.4, Diff: 7.1]
[Ext Root Scanning (ms): 3.8 4.0 3.5 3.2 3.8 0.0 0.0 0.0
Avg: 2.3, Min: 0.0, Max: 4.0, Diff: 4.0]
[Update RS (ms): 2.8 2.4 14.0 11.3 2.5 0.0 0.0 0.0
Avg: 4.1, Min: 0.0, Max: 14.0, Diff: 14.0]
[Processed Buffers : 4 30 5 5 29 0 0 0
Sum: 73, Avg: 9, Min: 0, Max: 30, Diff: 30]
[Scan RS (ms): 2.2 2.6 0.0 0.0 2.5 2.1 2.2 2.1
Avg: 1.7, Min: 0.0, Max: 2.6, Diff: 2.6]
[Object Copy (ms): 20.2 20.0 11.4 14.5 20.0 19.8 19.7 19.8
Avg: 18.2, Min: 11.4, Max: 20.2, Diff: 8.8]
[Termination (ms): 0.1 0.1 0.1 0.0 0.1 1.6 0.1 0.1
Avg: 0.3, Min: 0.0, Max: 1.6, Diff: 1.6]
[Termination Attempts : 17 25 29 1 25 27 29 27
Sum: 180, Avg: 22, Min: 1, Max: 29, Diff: 28]
[GC Worker End (ms): 17269.4 17269.4 17269.4 17269.4 17269.4 17270.9 17269.4 17269.4
Avg: 17269.6, Min: 17269.4, Max: 17270.9, Diff: 1.5]
[GC Worker (ms): 29.1 29.1 29.1 29.1 29.0 23.6 22.0 22.0
Avg: 26.6, Min: 22.0, Max: 29.1, Diff: 7.1]
[GC Worker Other (ms): 2.1 2.1 2.1 2.1 2.1 7.6 9.1 9.1
Avg: 4.5, Min: 2.1, Max: 9.1, Diff: 7.1]
[Clear CT: 0.1 ms]
[Other: 1.2 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.4 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.6 ms]
[Eden: 294M(308M)->0B(296M) Survivors: 11M->27M Heap: 395M(502M)->118M(502M)]
[Times: user=0.18 sys=0.00, real=0.03 secs]
20.476: [GC pause (young), 0.03165600 secs]
[Parallel Time: 30.7 ms]
[GC Worker Start (ms): 20476.3 20476.3 20476.3 20476.4 20476.4 20479.4 20479.4 20479.4
Avg: 20477.5, Min: 20476.3, Max: 20479.4, Diff: 3.1]
[Ext Root Scanning (ms): 3.6 3.2 3.3 3.2 2.9 1.0 0.0 0.0
Avg: 2.2, Min: 0.0, Max: 3.6, Diff: 3.6]
[Update RS (ms): 0.8 1.5 1.2 1.3 1.5 0.7 1.7 1.7
Avg: 1.3, Min: 0.7, Max: 1.7, Diff: 1.0]
[Processed Buffers : 24 2 11 4 4 10 4 3
Sum: 62, Avg: 7, Min: 2, Max: 24, Diff: 22]
[Scan RS (ms): 2.1 1.9 2.1 2.1 2.0 2.2 2.1 2.1
Avg: 2.1, Min: 1.9, Max: 2.2, Diff: 0.2]
[Object Copy (ms): 22.4 22.3 22.3 22.3 22.5 22.1 22.1 23.4
Avg: 22.4, Min: 22.1, Max: 23.4, Diff: 1.4]
[Termination (ms): 1.4 1.4 1.4 1.4 1.4 1.4 1.4 0.0
Avg: 1.2, Min: 0.0, Max: 1.4, Diff: 1.4]
[Termination Attempts : 8 8 6 5 4 10 5 1
Sum: 47, Avg: 5, Min: 1, Max: 10, Diff: 9]
[GC Worker End (ms): 20506.6 20506.6 20506.6 20506.6 20506.6 20506.6 20506.6 20506.6
Avg: 20506.6, Min: 20506.6, Max: 20506.6, Diff: 0.0]
[GC Worker (ms): 30.4 30.4 30.3 30.3 30.3 27.3 27.3 27.3
Avg: 29.2, Min: 27.3, Max: 30.4, Diff: 3.1]
[GC Worker Other (ms): 0.3 0.3 0.4 0.4 0.4 3.4 3.4 3.4
Avg: 1.5, Min: 0.3, Max: 3.4, Diff: 3.1]
[Clear CT: 0.1 ms]
[Other: 0.9 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.1 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.4 ms]
[Eden: 205M(296M)->0B(296M) Survivors: 27M->11M Heap: 323M(502M)->123M(502M)]
[Times: user=0.22 sys=0.00, real=0.03 secs]
24.527: [GC pause (young), 0.02939900 secs]
[Parallel Time: 28.0 ms]
[GC Worker Start (ms): 24526.8 24526.9 24526.9 24526.9 24526.9 24526.9 24533.9 24533.9
Avg: 24528.6, Min: 24526.8, Max: 24533.9, Diff: 7.1]
[Ext Root Scanning (ms): 3.2 2.6 3.1 2.9 3.5 2.9 0.0 0.0
Avg: 2.3, Min: 0.0, Max: 3.5, Diff: 3.5]
[Update RS (ms): 2.9 3.5 2.9 3.0 2.5 3.1 0.0 0.0
Avg: 2.2, Min: 0.0, Max: 3.5, Diff: 3.5]
[Processed Buffers : 10 6 29 5 22 13 0 0
Sum: 85, Avg: 10, Min: 0, Max: 29, Diff: 29]
[Scan RS (ms): 1.9 1.8 16.2 1.9 16.6 1.9 1.1 1.1
Avg: 5.3, Min: 1.1, Max: 16.6, Diff: 15.6]
[Object Copy (ms): 18.8 18.8 4.4 18.9 4.0 18.8 18.6 19.3
Avg: 15.2, Min: 4.0, Max: 19.3, Diff: 15.3]
[Termination (ms): 0.8 0.8 0.8 0.8 0.8 0.8 0.7 0.0
Avg: 0.7, Min: 0.0, Max: 0.8, Diff: 0.8]
[Termination Attempts : 1 3 2 2 3 1 1 1
Sum: 14, Avg: 1, Min: 1, Max: 3, Diff: 2]
[GC Worker End (ms): 24554.4 24554.4 24554.4 24554.4 24554.4 24554.4 24554.4 24554.3
Avg: 24554.4, Min: 24554.3, Max: 24554.4, Diff: 0.0]
[GC Worker (ms): 27.5 27.5 27.5 27.5 27.5 27.5 20.5 20.4
Avg: 25.7, Min: 20.4, Max: 27.5, Diff: 7.1]
[GC Worker Other (ms): 0.5 0.6 0.6 0.6 0.6 0.6 7.6 7.6
Avg: 2.3, Min: 0.5, Max: 7.6, Diff: 7.1]
[Clear CT: 0.1 ms]
[Other: 1.2 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.7 ms]
[Eden: 296M(296M)->0B(289M) Survivors: 11M->21M Heap: 419M(502M)->134M(502M)]
[Times: user=0.16 sys=0.00, real=0.03 secs]
27.023: [GC pause (young), 0.03782700 secs]
[Parallel Time: 36.6 ms]
[GC Worker Start (ms): 27023.2 27023.2 27023.2 27023.2 27023.3 27023.3 27023.3 27030.6
Avg: 27024.2, Min: 27023.2, Max: 27030.6, Diff: 7.4]
[Ext Root Scanning (ms): 2.3 3.1 2.6 2.9 3.1 2.4 2.5 0.0
Avg: 2.4, Min: 0.0, Max: 3.1, Diff: 3.1]
[Update RS (ms): 3.3 2.5 3.0 2.5 2.4 3.2 2.9 0.0
Avg: 2.5, Min: 0.0, Max: 3.3, Diff: 3.3]
[Processed Buffers : 15 5 12 4 18 5 22 0
Sum: 81, Avg: 10, Min: 0, Max: 22, Diff: 22]
[Scan RS (ms): 19.8 2.8 2.9 2.8 2.9 2.9 2.8 1.2
Avg: 4.8, Min: 1.2, Max: 19.8, Diff: 18.5]
[Object Copy (ms): 10.7 27.7 27.6 27.8 27.6 27.6 27.8 27.6
Avg: 25.5, Min: 10.7, Max: 27.8, Diff: 17.1]
[Termination (ms): 0.1 0.1 0.1 0.1 0.1 0.1 0.1 0.0
Avg: 0.1, Min: 0.0, Max: 0.1, Diff: 0.1]
[Termination Attempts : 1 1 4 1 1 1 1 1
Sum: 11, Avg: 1, Min: 1, Max: 4, Diff: 3]
[GC Worker End (ms): 27059.4 27059.4 27059.4 27059.4 27059.4 27059.4 27059.4 27059.4
Avg: 27059.4, Min: 27059.4, Max: 27059.4, Diff: 0.0]
[GC Worker (ms): 36.2 36.2 36.2 36.2 36.2 36.1 36.1 28.8
Avg: 35.2, Min: 28.8, Max: 36.2, Diff: 7.4]
[GC Worker Other (ms): 0.4 0.4 0.4 0.4 0.5 0.5 0.5 7.8
Avg: 1.4, Min: 0.4, Max: 7.8, Diff: 7.4]
[Clear CT: 0.2 ms]
[Other: 1.1 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.2 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.5 ms]
[Eden: 289M(289M)->0B(273M) Survivors: 21M->28M Heap: 423M(502M)->149M(502M)]
[Times: user=0.25 sys=0.00, real=0.03 secs]
2015-11-06T13:00:31,498 INFO [task-runner-0] io.druid.segment.realtime.plumber.RealtimePlumber - Submitting persist runnable for dataSource[MiddletiersBillingProd]
2015-11-06T13:00:31,500 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.realtime.plumber.RealtimePlumber - DataSource[MiddletiersBillingProd], Interval[2015-11-06T13:00:00.000Z/2015-11-06T14:00:00.000Z], persisting Hydrant[FireHydrant{index=io.druid.segment.incremental.OnheapIncrementalIndex@2b6ac7b5, queryable=io.druid.segment.ReferenceCountingSegment@6f5d5257, count=0}]
2015-11-06T13:00:31,506 INFO [MiddletiersBillingProd-incremental-persist] io.druid.guice.PropertiesModule - Loading properties from common.runtime.properties
2015-11-06T13:00:31,506 INFO [MiddletiersBillingProd-incremental-persist] io.druid.guice.PropertiesModule - Loading properties from runtime.properties
2015-11-06T13:00:31,513 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting persist for interval[2015-11-06T13:00:00.000Z/2015-11-06T13:01:00.000Z], rows[75,000]
2015-11-06T13:00:31,894 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - outDir[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/0/v8-tmp] completed index.drd in 5 millis.
2015-11-06T13:00:31,981 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - outDir[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/0/v8-tmp] completed dim conversions in 87 millis.
28.606: [GC pause (young), 0.05047600 secs]
[Parallel Time: 48.5 ms]
[GC Worker Start (ms): 28605.9 28605.9 28605.9 28605.9 28605.9 28605.9 28606.0 28616.6
Avg: 28607.2, Min: 28605.9, Max: 28616.6, Diff: 10.7]
[Ext Root Scanning (ms): 4.5 4.8 4.2 4.0 11.6 3.6 4.0 0.0
Avg: 4.6, Min: 0.0, Max: 11.6, Diff: 11.6]
[Update RS (ms): 3.5 3.5 3.3 3.9 0.0 4.3 4.3 0.0
Avg: 2.8, Min: 0.0, Max: 4.3, Diff: 4.3]
[Processed Buffers : 15 16 14 5 0 20 7 0
Sum: 77, Avg: 9, Min: 0, Max: 20, Diff: 20]
[Scan RS (ms): 4.0 13.4 4.0 3.7 0.6 24.5 3.6 1.6
Avg: 6.9, Min: 0.6, Max: 24.5, Diff: 23.9]
[Object Copy (ms): 36.0 26.4 36.4 36.3 35.6 15.7 36.0 35.6
Avg: 32.2, Min: 15.7, Max: 36.4, Diff: 20.8]
[Termination (ms): 0.2 0.1 0.2 0.2 0.2 0.0 0.2 0.2
Avg: 0.2, Min: 0.0, Max: 0.2, Diff: 0.2]
[Termination Attempts : 1 1 2 2 1 1 2 2
Sum: 12, Avg: 1, Min: 1, Max: 2, Diff: 1]
[GC Worker End (ms): 28654.0 28654.0 28654.0 28654.0 28654.0 28654.0 28654.0 28654.0
Avg: 28654.0, Min: 28654.0, Max: 28654.0, Diff: 0.0]
[GC Worker (ms): 48.1 48.1 48.1 48.1 48.1 48.1 48.0 37.4
Avg: 46.7, Min: 37.4, Max: 48.1, Diff: 10.7]
[GC Worker Other (ms): 0.4 0.4 0.4 0.4 0.4 0.5 0.5 11.1
Avg: 1.8, Min: 0.4, Max: 11.1, Diff: 10.7]
[Clear CT: 0.2 ms]
[Other: 1.7 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.9 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.5 ms]
[Eden: 273M(273M)->0B(254M) Survivors: 28M->32M Heap: 422M(502M)->163M(502M)]
[Times: user=0.28 sys=0.01, real=0.05 secs]
29.072: [GC pause (young), 0.05187700 secs]
[Parallel Time: 48.9 ms]
[GC Worker Start (ms): 29071.9 29071.9 29071.9 29071.9 29072.0 29080.0 29080.0 29086.9
Avg: 29075.8, Min: 29071.9, Max: 29086.9, Diff: 15.0]
[Ext Root Scanning (ms): 4.2 3.6 3.4 3.9 3.7 0.0 0.0 0.0
Avg: 2.4, Min: 0.0, Max: 4.2, Diff: 4.2]
[Update RS (ms): 2.0 2.6 3.0 2.4 2.4 0.0 0.0 0.0
Avg: 1.6, Min: 0.0, Max: 3.0, Diff: 3.0]
[Processed Buffers : 16 22 5 4 7 0 0 0
Sum: 54, Avg: 6, Min: 0, Max: 22, Diff: 22]
[Scan RS (ms): 16.7 3.6 3.5 12.0 3.5 2.1 2.0 0.1
Avg: 5.4, Min: 0.1, Max: 16.7, Diff: 16.5]
[Object Copy (ms): 25.5 38.7 38.5 30.0 38.7 38.3 38.4 33.2
Avg: 35.2, Min: 25.5, Max: 38.7, Diff: 13.2]
[Termination (ms): 0.1 0.0 0.1 0.1 0.1 0.0 0.0 0.1
Avg: 0.1, Min: 0.0, Max: 0.1, Diff: 0.1]
[Termination Attempts : 1 1 1 1 1 1 1 1
Sum: 8, Avg: 1, Min: 1, Max: 1, Diff: 0]
[GC Worker End (ms): 29120.4 29120.4 29120.4 29120.4 29120.4 29120.4 29120.4 29120.4
Avg: 29120.4, Min: 29120.4, Max: 29120.4, Diff: 0.0]
[GC Worker (ms): 48.5 48.5 48.5 48.4 48.4 40.4 40.4 33.5
Avg: 44.6, Min: 33.5, Max: 48.5, Diff: 15.0]
[GC Worker Other (ms): 0.4 0.4 0.4 0.4 0.5 8.5 8.5 15.4
Avg: 4.3, Min: 0.4, Max: 15.4, Diff: 15.0]
[Clear CT: 0.3 ms]
[Other: 2.7 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 1.9 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.5 ms]
[Eden: 254M(254M)->0B(260M) Survivors: 32M->22M Heap: 417M(502M)->168M(502M)]
[Times: user=0.24 sys=0.00, real=0.05 secs]
29.971: [GC pause (young), 0.05120200 secs]
[Parallel Time: 49.6 ms]
[GC Worker Start (ms): 29970.9 29970.9 29970.9 29971.1 29981.8 29981.8 29981.8 29981.9
Avg: 29976.4, Min: 29970.9, Max: 29981.9, Diff: 11.0]
[Ext Root Scanning (ms): 5.1 5.2 5.2 4.2 0.0 0.0 0.0 0.0
Avg: 2.5, Min: 0.0, Max: 5.2, Diff: 5.2]
[Update RS (ms): 3.1 3.2 3.0 4.0 0.0 0.0 0.0 0.0
Avg: 1.7, Min: 0.0, Max: 4.0, Diff: 4.0]
[Processed Buffers : 6 20 20 14 0 0 0 0
Sum: 60, Avg: 7, Min: 0, Max: 20, Diff: 20]
[Scan RS (ms): 1.2 1.3 1.2 1.3 0.0 0.0 0.0 0.0
Avg: 0.6, Min: 0.0, Max: 1.3, Diff: 1.3]
[Object Copy (ms): 26.4 26.1 26.3 26.1 24.9 34.7 24.8 25.1
Avg: 26.8, Min: 24.8, Max: 34.7, Diff: 9.9]
[Termination (ms): 9.9 9.9 9.9 9.9 9.8 0.0 9.9 13.0
Avg: 9.0, Min: 0.0, Max: 13.0, Diff: 13.0]
[Termination Attempts : 2 1 1 1 1 1 1 1
Sum: 9, Avg: 1, Min: 1, Max: 2, Diff: 1]
[GC Worker End (ms): 30016.5 30016.5 30016.6 30016.6 30016.6 30016.5 30016.5 30020.0
Avg: 30017.0, Min: 30016.5, Max: 30020.0, Diff: 3.4]
[GC Worker (ms): 45.7 45.7 45.7 45.5 34.7 34.7 34.7 38.1
Avg: 40.6, Min: 34.7, Max: 45.7, Diff: 11.0]
[GC Worker Other (ms): 4.0 4.0 4.0 4.1 14.9 15.0 15.0 11.6
Avg: 9.1, Min: 4.0, Max: 15.0, Diff: 11.0]
[Clear CT: 0.2 ms]
[Other: 1.4 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.4 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.7 ms]
[Eden: 260M(260M)->0B(254M) Survivors: 22M->17M Heap: 428M(502M)->176M(502M)]
[Times: user=0.23 sys=0.00, real=0.06 secs]
2015-11-06T13:00:33,990 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - outDir[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/0/v8-tmp] completed walk through of 75,000 rows in 2,009 millis.
2015-11-06T13:00:33,992 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[adid] with cardinality[1,679]
2015-11-06T13:00:34,144 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[adid] in 154 millis.
2015-11-06T13:00:34,144 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[age] with cardinality[8]
2015-11-06T13:00:34,186 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[age] in 42 millis.
2015-11-06T13:00:34,187 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[billingType] with cardinality[7]
2015-11-06T13:00:34,195 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[billingType] in 8 millis.
2015-11-06T13:00:34,196 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[city] with cardinality[36]
2015-11-06T13:00:34,233 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[city] in 38 millis.
2015-11-06T13:00:34,233 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[dsp] with cardinality[6]
2015-11-06T13:00:34,241 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[dsp] in 7 millis.
2015-11-06T13:00:34,241 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[education] with cardinality[0]
2015-11-06T13:00:34,242 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[education] in 1 millis.
2015-11-06T13:00:34,242 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expAppId] with cardinality[5]
2015-11-06T13:00:34,249 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expAppId] in 6 millis.
2015-11-06T13:00:34,249 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer1] with cardinality[9]
2015-11-06T13:00:34,256 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer1] in 7 millis.
2015-11-06T13:00:34,256 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer2] with cardinality[4]
2015-11-06T13:00:34,263 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer2] in 7 millis.
2015-11-06T13:00:34,263 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer3] with cardinality[3]
2015-11-06T13:00:34,269 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer3] in 6 millis.
2015-11-06T13:00:34,270 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer4] with cardinality[6]
2015-11-06T13:00:34,277 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer4] in 7 millis.
2015-11-06T13:00:34,277 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer5] with cardinality[7]
2015-11-06T13:00:34,284 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer5] in 7 millis.
2015-11-06T13:00:34,284 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer6] with cardinality[3]
2015-11-06T13:00:34,290 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer6] in 6 millis.
2015-11-06T13:00:34,291 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer7] with cardinality[2]
2015-11-06T13:00:34,297 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer7] in 6 millis.
2015-11-06T13:00:34,297 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer8] with cardinality[2]
2015-11-06T13:00:34,304 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer8] in 7 millis.
2015-11-06T13:00:34,305 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[experimentId] with cardinality[42]
2015-11-06T13:00:34,314 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[experimentId] in 10 millis.
2015-11-06T13:00:34,314 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[gender] with cardinality[3]
2015-11-06T13:00:34,345 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[gender] in 31 millis.
2015-11-06T13:00:34,345 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[incomeLevel] with cardinality[0]
2015-11-06T13:00:34,346 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[incomeLevel] in 1 millis.
2015-11-06T13:00:34,346 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[mediaType] with cardinality[21]
2015-11-06T13:00:34,379 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[mediaType] in 33 millis.
2015-11-06T13:00:34,380 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[pageId] with cardinality[87]
2015-11-06T13:00:34,401 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[pageId] in 22 millis.
2015-11-06T13:00:34,402 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[platform] with cardinality[5]
2015-11-06T13:00:34,408 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[platform] in 7 millis.
2015-11-06T13:00:34,408 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[posId] with cardinality[3]
2015-11-06T13:00:34,413 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[posId] in 5 millis.
2015-11-06T13:00:34,414 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[province] with cardinality[35]
2015-11-06T13:00:35,058 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[province] in 644 millis.
2015-11-06T13:00:35,058 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[refType] with cardinality[3]
2015-11-06T13:00:35,061 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[refType] in 3 millis.
2015-11-06T13:00:35,062 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[reqType] with cardinality[4]
2015-11-06T13:00:35,068 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[reqType] in 6 millis.
2015-11-06T13:00:35,068 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[sessionId] with cardinality[27]
2015-11-06T13:00:35,073 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[sessionId] in 5 millis.
2015-11-06T13:00:35,073 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[tagId] with cardinality[39]
2015-11-06T13:00:35,079 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[tagId] in 6 millis.
2015-11-06T13:00:35,080 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[templateId] with cardinality[18]
2015-11-06T13:00:35,088 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[templateId] in 7 millis.
2015-11-06T13:00:35,088 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - outDir[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/0/v8-tmp] completed inverted.drd in 1,098 millis.
2015-11-06T13:00:35,117 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Converting v8[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/0/v8-tmp] to v9[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/0]
2015-11-06T13:00:35,119 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_adid.drd]
2015-11-06T13:00:35,181 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[adid] is single value, converting…
31.391: [GC pause (young), 0.06004700 secs]
[Parallel Time: 49.4 ms]
[GC Worker Start (ms): 31391.3 31391.3 31391.3 31398.4 31403.6 31403.6 31409.7 31409.7
Avg: 31399.9, Min: 31391.3, Max: 31409.7, Diff: 18.5]
[Ext Root Scanning (ms): 11.9 7.5 6.8 1.0 0.0 0.0 0.0 0.0
Avg: 3.4, Min: 0.0, Max: 11.9, Diff: 11.9]
[Update RS (ms): 0.6 5.2 5.5 14.3 1.0 1.0 0.0 0.0
Avg: 3.5, Min: 0.0, Max: 14.3, Diff: 14.3]
[Processed Buffers : 12 26 9 7 17 2 0 0
Sum: 73, Avg: 9, Min: 0, Max: 26, Diff: 26]
[Scan RS (ms): 0.4 0.5 0.3 0.0 0.5 0.4 0.0 0.0
Avg: 0.3, Min: 0.0, Max: 0.5, Diff: 0.5]
[Object Copy (ms): 32.1 31.7 32.3 22.4 31.8 31.1 27.2 26.3
Avg: 29.4, Min: 22.4, Max: 32.3, Diff: 9.9]
[Termination (ms): 0.8 0.9 0.8 0.9 0.1 0.9 0.0 0.9
Avg: 0.7, Min: 0.0, Max: 0.9, Diff: 0.9]
[Termination Attempts : 1 4 1 1 1 3 1 1
Sum: 13, Avg: 1, Min: 1, Max: 4, Diff: 3]
[GC Worker End (ms): 31437.0 31437.0 31437.0 31437.0 31437.0 31437.0 31437.0 31437.0
Avg: 31437.0, Min: 31437.0, Max: 31437.0, Diff: 0.0]
[GC Worker (ms): 45.8 45.7 45.7 38.6 33.4 33.4 27.3 27.3
Avg: 37.2, Min: 27.3, Max: 45.8, Diff: 18.5]
[GC Worker Other (ms): 3.7 3.7 3.7 10.8 16.0 16.0 22.2 22.1
Avg: 12.3, Min: 3.7, Max: 22.2, Diff: 18.5]
[Clear CT: 0.2 ms]
[Other: 10.5 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 9.6 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.6 ms]
[Eden: 254M(254M)->0B(230M) Survivors: 17M->30M Heap: 430M(502M)->190M(502M)]
[Times: user=0.26 sys=0.00, real=0.06 secs]
2015-11-06T13:00:35,329 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_age.drd]
2015-11-06T13:00:35,331 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[age] is single value, converting…
2015-11-06T13:00:35,349 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_billingType.drd]
2015-11-06T13:00:35,376 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[billingType] is single value, converting…
2015-11-06T13:00:35,376 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[billingType] has null rows.
2015-11-06T13:00:35,400 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_city.drd]
2015-11-06T13:00:35,411 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[city] is single value, converting…
2015-11-06T13:00:35,411 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[city] has null rows.
2015-11-06T13:00:35,482 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_dsp.drd]
2015-11-06T13:00:35,506 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[dsp] is single value, converting…
2015-11-06T13:00:35,506 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[dsp] has null rows.
2015-11-06T13:00:35,532 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_education.drd]
2015-11-06T13:00:35,532 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[education] had cardinality 0, equivalent to no column, so skipping.
2015-11-06T13:00:35,532 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expAppId.drd]
2015-11-06T13:00:35,545 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expAppId] is single value, converting…
2015-11-06T13:00:35,545 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expAppId] has null rows.
2015-11-06T13:00:35,568 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer1.drd]
2015-11-06T13:00:35,573 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer1] is single value, converting…
2015-11-06T13:00:35,573 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer1] has null rows.
2015-11-06T13:00:35,594 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer2.drd]
2015-11-06T13:00:35,610 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer2] is single value, converting…
2015-11-06T13:00:35,610 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer2] has null rows.
2015-11-06T13:00:35,644 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer3.drd]
2015-11-06T13:00:35,657 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer3] is single value, converting…
2015-11-06T13:00:35,657 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer3] has null rows.
2015-11-06T13:00:35,679 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer4.drd]
31.881: [GC pause (young), 0.06208100 secs]
[Parallel Time: 54.2 ms]
[GC Worker Start (ms): 31881.6 31881.6 31881.6 31888.1 31893.5 31893.5 31898.6 31904.2
Avg: 31890.3, Min: 31881.6, Max: 31904.2, Diff: 22.6]
[Ext Root Scanning (ms): 6.2 6.5 30.1 0.0 0.0 0.0 0.0 0.0
Avg: 5.4, Min: 0.0, Max: 30.1, Diff: 30.1]
[Update RS (ms): 2.0 1.9 0.0 2.5 0.0 0.0 0.0 0.0
Avg: 0.8, Min: 0.0, Max: 2.5, Diff: 2.5]
[Processed Buffers : 17 13 0 13 0 0 0 0
Sum: 43, Avg: 5, Min: 0, Max: 17, Diff: 17]
[Scan RS (ms): 0.1 0.1 0.0 0.1 0.0 0.0 0.0 0.0
Avg: 0.1, Min: 0.0, Max: 0.1, Diff: 0.1]
[Object Copy (ms): 37.6 37.3 15.9 36.7 33.9 33.8 28.8 30.9
Avg: 31.9, Min: 15.9, Max: 37.6, Diff: 21.7]
[Termination (ms): 7.8 7.8 7.6 7.8 7.7 7.8 7.7 0.0
Avg: 6.8, Min: 0.0, Max: 7.8, Diff: 7.8]
[Termination Attempts : 2 3 1 1 1 1 1 1
Sum: 11, Avg: 1, Min: 1, Max: 3, Diff: 2]
[GC Worker End (ms): 31935.2 31935.2 31935.2 31935.2 31935.2 31935.2 31935.2 31935.2
Avg: 31935.2, Min: 31935.2, Max: 31935.2, Diff: 0.0]
[GC Worker (ms): 53.6 53.6 53.6 47.1 41.7 41.6 36.6 31.0
Avg: 44.8, Min: 31.0, Max: 53.6, Diff: 22.6]
[GC Worker Other (ms): 0.6 0.6 0.6 7.1 12.5 12.5 17.6 23.2
Avg: 9.4, Min: 0.6, Max: 23.2, Diff: 22.6]
[Clear CT: 0.2 ms]
[Other: 7.7 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 6.8 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.6 ms]
[Eden: 230M(230M)->0B(243M) Survivors: 30M->17M Heap: 420M(502M)->190M(502M)]
[Times: user=0.27 sys=0.00, real=0.07 secs]
2015-11-06T13:00:35,783 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer4] is single value, converting…
2015-11-06T13:00:35,784 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer4] has null rows.
2015-11-06T13:00:35,845 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer5.drd]
2015-11-06T13:00:35,866 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer5] is single value, converting…
2015-11-06T13:00:35,866 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer5] has null rows.
2015-11-06T13:00:35,893 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer6.drd]
2015-11-06T13:00:35,899 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer6] is single value, converting…
2015-11-06T13:00:35,899 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer6] has null rows.
2015-11-06T13:00:35,926 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer7.drd]
2015-11-06T13:00:35,932 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer7] is single value, converting…
2015-11-06T13:00:35,932 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer7] has null rows.
2015-11-06T13:00:35,958 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer8.drd]
2015-11-06T13:00:35,961 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer8] is single value, converting…
2015-11-06T13:00:35,962 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer8] has null rows.
2015-11-06T13:00:35,989 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_experimentId.drd]
2015-11-06T13:00:35,995 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[experimentId] is single value, converting…
2015-11-06T13:00:35,995 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[experimentId] has null rows.
2015-11-06T13:00:36,016 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_gender.drd]
2015-11-06T13:00:36,020 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[gender] is single value, converting…
2015-11-06T13:00:36,061 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_incomeLevel.drd]
2015-11-06T13:00:36,061 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[incomeLevel] had cardinality 0, equivalent to no column, so skipping.
2015-11-06T13:00:36,062 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_mediaType.drd]
2015-11-06T13:00:36,065 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[mediaType] is single value, converting…
2015-11-06T13:00:36,087 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_pageId.drd]
2015-11-06T13:00:36,092 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[pageId] is single value, converting…
2015-11-06T13:00:36,093 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[pageId] has null rows.
2015-11-06T13:00:36,112 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_platform.drd]
2015-11-06T13:00:36,118 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[platform] is single value, converting…
2015-11-06T13:00:36,118 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[platform] has null rows.
2015-11-06T13:00:36,155 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_posId.drd]
2015-11-06T13:00:36,159 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[posId] is single value, converting…
2015-11-06T13:00:36,159 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[posId] has null rows.
32.364: [GC pause (young), 0.03396900 secs]
[Parallel Time: 29.8 ms]
[GC Worker Start (ms): 32364.3 32364.3 32364.3 32364.3 32364.4 32371.1 32378.8 32378.8
Avg: 32368.8, Min: 32364.3, Max: 32378.8, Diff: 14.5]
[Ext Root Scanning (ms): 3.9 4.3 4.2 4.5 3.6 0.0 0.0 0.0
Avg: 2.6, Min: 0.0, Max: 4.5, Diff: 4.5]
[Update RS (ms): 3.1 3.0 2.7 3.1 3.9 1.1 0.0 0.0
Avg: 2.1, Min: 0.0, Max: 3.9, Diff: 3.9]
[Processed Buffers : 14 12 15 6 9 3 0 0
Sum: 59, Avg: 7, Min: 0, Max: 15, Diff: 15]
[Scan RS (ms): 1.3 1.4 1.3 0.9 1.2 1.2 0.0 0.0
Avg: 0.9, Min: 0.0, Max: 1.4, Diff: 1.4]
[Object Copy (ms): 20.0 19.6 20.1 19.8 19.8 19.2 13.9 13.8
Avg: 18.3, Min: 13.8, Max: 20.1, Diff: 6.3]
[Termination (ms): 0.1 0.1 0.1 0.1 0.0 0.1 0.0 0.9
Avg: 0.2, Min: 0.0, Max: 0.9, Diff: 0.9]
[Termination Attempts : 2 1 2 1 1 1 1 1
Sum: 10, Avg: 1, Min: 1, Max: 2, Diff: 1]
[GC Worker End (ms): 32392.8 32392.8 32392.8 32392.8 32392.8 32392.8 32392.8 32393.5
Avg: 32392.9, Min: 32392.8, Max: 32393.5, Diff: 0.8]
[GC Worker (ms): 28.5 28.4 28.4 28.4 28.4 21.6 14.0 14.7
Avg: 24.1, Min: 14.0, Max: 28.5, Diff: 14.5]
[GC Worker Other (ms): 1.4 1.4 1.4 1.5 1.5 8.2 15.9 15.1
Avg: 5.8, Min: 1.4, Max: 15.9, Diff: 14.5]
[Clear CT: 0.2 ms]
[Other: 4.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 3.2 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.6 ms]
[Eden: 243M(243M)->0B(237M) Survivors: 17M->20M Heap: 433M(502M)->193M(502M)]
[Times: user=0.14 sys=0.00, real=0.03 secs]
2015-11-06T13:00:36,214 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_province.drd]
2015-11-06T13:00:36,218 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[province] is single value, converting…
2015-11-06T13:00:36,237 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_refType.drd]
2015-11-06T13:00:36,243 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[refType] is single value, converting…
2015-11-06T13:00:36,243 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[refType] has null rows.
2015-11-06T13:00:36,266 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_reqType.drd]
2015-11-06T13:00:36,271 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[reqType] is single value, converting…
2015-11-06T13:00:36,271 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[reqType] has null rows.
2015-11-06T13:00:36,293 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_sessionId.drd]
2015-11-06T13:00:36,299 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[sessionId] is single value, converting…
2015-11-06T13:00:36,299 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[sessionId] has null rows.
2015-11-06T13:00:36,321 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_tagId.drd]
2015-11-06T13:00:36,327 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[tagId] is single value, converting…
2015-11-06T13:00:36,327 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[tagId] has null rows.
2015-11-06T13:00:36,348 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_templateId.drd]
2015-11-06T13:00:36,353 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[templateId] is single value, converting…
2015-11-06T13:00:36,354 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[templateId] has null rows.
2015-11-06T13:00:36,374 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[index.drd]
2015-11-06T13:00:36,375 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[inverted.drd]
2015-11-06T13:00:36,375 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_click_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,379 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_count_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,379 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_endDownload_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,380 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_endInstall_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,380 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_expose_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,380 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_fee_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,381 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_loaded_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,381 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_queryFailed_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,381 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_query_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,381 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_startDownload_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,382 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_startInstall_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,382 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[spatial.drd]
2015-11-06T13:00:36,382 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[time_LITTLE_ENDIAN.drd]
2015-11-06T13:00:36,385 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Skipped files[[index.drd, inverted.drd, spatial.drd]]
2015-11-06T13:00:36,428 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.ReferenceCountingSegment - Closing MiddletiersBillingProd_2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z_2015-11-06T13:00:12.828Z
2015-11-06T13:00:36,428 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.ReferenceCountingSegment - Closing MiddletiersBillingProd_2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z_2015-11-06T13:00:12.828Z, numReferences: 0
34.092: [GC pause (young), 0.03121600 secs]
[Parallel Time: 30.1 ms]
[GC Worker Start (ms): 34092.2 34092.3 34092.3 34092.3 34099.3 34106.8 34108.6 34108.6
Avg: 34099.0, Min: 34092.2, Max: 34108.6, Diff: 16.3]
[Ext Root Scanning (ms): 4.9 3.9 4.1 4.3 0.0 0.0 0.0 0.0
Avg: 2.1, Min: 0.0, Max: 4.9, Diff: 4.9]
[Update RS (ms): 2.1 23.4 2.8 2.7 0.1 0.0 0.0 0.0
Avg: 3.9, Min: 0.0, Max: 23.4, Diff: 23.4]
[Processed Buffers : 17 8 26 7 5 0 0 0
Sum: 63, Avg: 7, Min: 0, Max: 26, Diff: 26]
[Scan RS (ms): 0.1 0.0 0.1 0.0 0.1 0.0 0.0 0.0
Avg: 0.0, Min: 0.0, Max: 0.1, Diff: 0.1]
[Object Copy (ms): 21.0 0.6 21.0 21.0 20.7 15.1 11.8 11.7
Avg: 15.3, Min: 0.6, Max: 21.0, Diff: 20.5]
[Termination (ms): 1.6 1.6 1.7 1.6 1.6 0.0 1.6 1.6
Avg: 1.4, Min: 0.0, Max: 1.7, Diff: 1.7]
[Termination Attempts : 1 1 1 1 1 1 1 1
Sum: 8, Avg: 1, Min: 1, Max: 1, Diff: 0]
[GC Worker End (ms): 34121.9 34121.9 34121.9 34121.9 34121.9 34121.9 34121.9 34121.9
Avg: 34121.9, Min: 34121.9, Max: 34121.9, Diff: 0.0]
[GC Worker (ms): 29.7 29.6 29.6 29.6 22.6 15.1 13.4 13.3
Avg: 22.9, Min: 13.3, Max: 29.7, Diff: 16.3]
[GC Worker Other (ms): 0.5 0.5 0.5 0.5 7.6 15.0 16.8 16.8
Avg: 7.3, Min: 0.5, Max: 16.8, Diff: 16.3]
[Clear CT: 0.1 ms]
[Other: 0.9 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.4 ms]
[Eden: 237M(237M)->0B(240M) Survivors: 20M->11M Heap: 430M(502M)->197M(502M)]
[Times: user=0.15 sys=0.01, real=0.04 secs]
35.050: [GC pause (young), 0.04075000 secs]
[Parallel Time: 39.5 ms]
[GC Worker Start (ms): 35050.2 35050.2 35053.2 35053.2 35053.2 35053.3 35056.3 35059.4
Avg: 35053.6, Min: 35050.2, Max: 35059.4, Diff: 9.2]
[Ext Root Scanning (ms): 4.9 4.8 3.0 3.1 2.1 2.1 0.0 0.0
Avg: 2.5, Min: 0.0, Max: 4.9, Diff: 4.9]
[Update RS (ms): 5.9 8.2 4.9 4.9 11.4 5.9 5.1 1.9
Avg: 6.0, Min: 1.9, Max: 11.4, Diff: 9.5]
[Processed Buffers : 11 1 9 30 9 10 24 11
Sum: 105, Avg: 13, Min: 1, Max: 30, Diff: 29]
[Scan RS (ms): 1.3 0.0 1.4 1.3 0.0 1.4 1.4 1.4
Avg: 1.0, Min: 0.0, Max: 1.4, Diff: 1.4]
[Object Copy (ms): 17.2 25.8 16.9 17.0 12.7 16.9 16.7 22.5
Avg: 18.2, Min: 12.7, Max: 25.8, Diff: 13.0]
[Termination (ms): 9.4 0.0 9.5 9.5 9.5 9.5 9.5 3.8
Avg: 7.6, Min: 0.0, Max: 9.5, Diff: 9.5]
[Termination Attempts : 7 1 10 12 14 1 11 1
Sum: 57, Avg: 7, Min: 1, Max: 14, Diff: 13]
[GC Worker End (ms): 35089.0 35089.0 35089.0 35089.0 35089.0 35089.0 35089.0 35089.0
Avg: 35089.0, Min: 35089.0, Max: 35089.0, Diff: 0.0]
[GC Worker (ms): 38.8 38.8 35.8 35.7 35.7 35.7 32.7 29.6
Avg: 35.4, Min: 29.6, Max: 38.8, Diff: 9.2]
[GC Worker Other (ms): 0.7 0.7 3.7 3.8 3.7 3.8 6.8 9.9
Avg: 4.1, Min: 0.7, Max: 9.9, Diff: 9.2]
[Clear CT: 0.1 ms]
[Other: 1.1 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.6 ms]
[Eden: 240M(240M)->0B(222M) Survivors: 11M->21M Heap: 437M(502M)->207M(502M)]
[Times: user=0.20 sys=0.00, real=0.04 secs]
2015-11-06T13:00:39,062 INFO [ServerInventoryView-0] io.druid.curator.inventory.CuratorInventoryManager - Created new InventoryCacheListener for /druid/prod/segments/hh-miui-ad-preview01.bj:8106
2015-11-06T13:00:39,062 INFO [ServerInventoryView-0] io.druid.client.BatchServerInventoryView - New Server[DruidServerMetadata{name=‘hh-miui-ad-preview01.bj:8106’, host=‘hh-miui-ad-preview01.bj:8106’, maxSize=0, tier=’_default_tier’, type=‘realtime’, priority=‘0’}]
38.580: [GC pause (young), 0.03772200 secs]
[Parallel Time: 36.7 ms]
[GC Worker Start (ms): 38579.8 38579.8 38579.8 38579.8 38579.8 38579.8 38590.6 38590.6
Avg: 38582.5, Min: 38579.8, Max: 38590.6, Diff: 10.8]
[Ext Root Scanning (ms): 3.2 3.8 3.0 3.2 3.8 3.0 0.0 0.0
Avg: 2.5, Min: 0.0, Max: 3.8, Diff: 3.8]
[Update RS (ms): 4.6 4.1 4.6 4.5 4.1 4.6 0.0 0.0
Avg: 3.3, Min: 0.0, Max: 4.6, Diff: 4.6]
[Processed Buffers : 24 7 19 18 7 21 0 0
Sum: 96, Avg: 12, Min: 0, Max: 24, Diff: 24]
[Scan RS (ms): 0.1 0.0 0.1 0.1 0.0 0.1 0.0 0.0
Avg: 0.0, Min: 0.0, Max: 0.1, Diff: 0.1]
[Object Copy (ms): 27.3 27.3 27.5 27.3 27.2 27.4 24.4 25.3
Avg: 26.7, Min: 24.4, Max: 27.5, Diff: 3.1]
[Termination (ms): 1.0 1.0 1.0 1.0 1.0 1.0 0.9 0.0
Avg: 0.8, Min: 0.0, Max: 1.0, Diff: 1.0]
[Termination Attempts : 8 2 11 6 8 13 1 1
Sum: 50, Avg: 6, Min: 1, Max: 13, Diff: 12]
[GC Worker End (ms): 38615.9 38615.9 38615.9 38615.9 38615.9 38615.9 38615.9 38615.9
Avg: 38615.9, Min: 38615.9, Max: 38615.9, Diff: 0.0]
[GC Worker (ms): 36.1 36.1 36.1 36.1 36.1 36.1 25.4 25.3
Avg: 33.4, Min: 25.3, Max: 36.1, Diff: 10.8]
[GC Worker Other (ms): 0.6 0.6 0.6 0.6 0.6 0.6 11.4 11.4
Avg: 3.3, Min: 0.6, Max: 11.4, Diff: 10.8]
[Clear CT: 0.2 ms]
[Other: 0.8 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.2 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.4 ms]
[Eden: 222M(222M)->0B(211M) Survivors: 21M->22M Heap: 429M(502M)->217M(502M)]
[Times: user=0.22 sys=0.01, real=0.04 secs]
39.738: [GC pause (young), 0.04528700 secs]
[Parallel Time: 44.0 ms]
[GC Worker Start (ms): 39737.9 39737.9 39738.0 39738.0 39738.0 39742.0 39742.0 39742.0
Avg: 39739.5, Min: 39737.9, Max: 39742.0, Diff: 4.1]
[Ext Root Scanning (ms): 4.0 3.7 10.6 3.6 4.1 0.0 0.0 0.0
Avg: 3.2, Min: 0.0, Max: 10.6, Diff: 10.6]
[Update RS (ms): 5.7 7.4 0.0 6.1 5.7 6.0 7.8 6.0
Avg: 5.6, Min: 0.0, Max: 7.8, Diff: 7.8]
[Processed Buffers : 11 1 0 6 24 22 12 24
Sum: 100, Avg: 12, Min: 0, Max: 24, Diff: 24]
[Scan RS (ms): 2.1 1.0 1.4 12.6 2.3 5.3 0.4 6.8
Avg: 4.0, Min: 0.4, Max: 12.6, Diff: 12.1]
[Object Copy (ms): 31.7 31.4 31.6 21.2 31.3 28.1 31.2 26.6
Avg: 29.1, Min: 21.2, Max: 31.7, Diff: 10.5]
[Termination (ms): 0.1 0.1 0.0 0.1 0.1 0.0 0.1 0.1
Avg: 0.1, Min: 0.0, Max: 0.1, Diff: 0.1]
[Termination Attempts : 6 3 1 5 4 2 5 4
Sum: 30, Avg: 3, Min: 1, Max: 6, Diff: 5]
[GC Worker End (ms): 39781.5 39781.5 39781.5 39781.5 39781.5 39781.5 39781.5 39781.5
Avg: 39781.5, Min: 39781.5, Max: 39781.5, Diff: 0.0]
[GC Worker (ms): 43.6 43.6 43.6 43.6 43.6 39.5 39.5 39.5
Avg: 42.1, Min: 39.5, Max: 43.6, Diff: 4.1]
[GC Worker Other (ms): 0.5 0.4 0.5 0.5 0.5 4.5 4.5 4.5
Avg: 2.0, Min: 0.4, Max: 4.5, Diff: 4.1]
[Clear CT: 0.1 ms]
[Other: 1.1 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.5 ms]
[Eden: 211M(211M)->0B(197M) Survivors: 22M->24M Heap: 428M(502M)->228M(502M)]
[Times: user=0.24 sys=0.00, real=0.05 secs]
41.838: [GC pause (young), 0.03495100 secs]
[Parallel Time: 33.9 ms]
[GC Worker Start (ms): 41838.2 41838.2 41838.2 41838.2 41838.2 41843.3 41845.7 41845.7
Avg: 41840.7, Min: 41838.2, Max: 41845.7, Diff: 7.6]
[Ext Root Scanning (ms): 3.0 3.2 3.5 3.3 3.7 0.0 0.0 0.0
Avg: 2.1, Min: 0.0, Max: 3.7, Diff: 3.6]
[Update RS (ms): 5.6 5.5 15.2 5.3 4.9 3.7 1.3 1.4
Avg: 5.4, Min: 1.3, Max: 15.2, Diff: 13.9]
[Processed Buffers : 10 10 11 23 22 21 4 3
Sum: 104, Avg: 13, Min: 3, Max: 23, Diff: 20]
[Scan RS (ms): 1.4 1.5 0.0 1.5 1.5 1.5 1.5 1.4
Avg: 1.3, Min: 0.0, Max: 1.5, Diff: 1.5]
[Object Copy (ms): 21.7 21.5 14.5 21.6 21.6 21.3 21.3 21.3
Avg: 20.6, Min: 14.5, Max: 21.7, Diff: 7.2]
[Termination (ms): 1.5 1.5 0.0 1.5 1.5 1.5 1.5 1.5
Avg: 1.3, Min: 0.0, Max: 1.5, Diff: 1.5]
[Termination Attempts : 3 2 1 2 1 2 2 1
Sum: 14, Avg: 1, Min: 1, Max: 3, Diff: 2]
[GC Worker End (ms): 41871.3 41871.3 41871.3 41871.3 41871.3 41871.4 41871.3 41871.3
Avg: 41871.3, Min: 41871.3, Max: 41871.4, Diff: 0.0]
[GC Worker (ms): 33.2 33.2 33.1 33.1 33.1 28.1 25.6 25.6
Avg: 30.6, Min: 25.6, Max: 33.2, Diff: 7.6]
[GC Worker Other (ms): 0.7 0.7 0.8 0.8 0.8 5.8 8.3 8.3
Avg: 3.3, Min: 0.7, Max: 8.3, Diff: 7.6]
[Clear CT: 0.1 ms]
[Other: 0.9 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.4 ms]
[Eden: 197M(197M)->0B(197M) Survivors: 24M->19M Heap: 425M(502M)->234M(502M)]
[Times: user=0.22 sys=0.00, real=0.03 secs]
44.614: [GC pause (young), 0.03688000 secs]
[Parallel Time: 35.8 ms]
[GC Worker Start (ms): 44613.7 44613.7 44613.7 44613.7 44613.7 44613.7 44613.7 44613.7
Avg: 44613.7, Min: 44613.7, Max: 44613.7, Diff: 0.1]
[Ext Root Scanning (ms): 2.2 2.3 2.0 2.2 3.1 2.3 2.8 2.6
Avg: 2.4, Min: 2.0, Max: 3.1, Diff: 1.1]
[Update RS (ms): 5.5 15.1 5.5 5.5 4.5 5.5 4.8 5.1
Avg: 6.4, Min: 4.5, Max: 15.1, Diff: 10.5]
[Processed Buffers : 17 9 20 14 13 10 20 10
Sum: 113, Avg: 14, Min: 9, Max: 20, Diff: 11]
[Scan RS (ms): 1.2 0.0 1.1 1.2 1.2 1.1 1.1 1.1
Avg: 1.0, Min: 0.0, Max: 1.2, Diff: 1.2]
[Object Copy (ms): 26.3 15.7 20.8 20.6 20.6 20.6 20.8 20.6
Avg: 20.8, Min: 15.7, Max: 26.3, Diff: 10.7]
[Termination (ms): 0.0 2.3 5.8 5.8 5.8 5.8 5.8 5.8
Avg: 4.6, Min: 0.0, Max: 5.8, Diff: 5.8]
[Termination Attempts : 1 1 4 4 3 6 4 4
Sum: 27, Avg: 3, Min: 1, Max: 6, Diff: 5]
[GC Worker End (ms): 44649.0 44649.0 44649.0 44649.0 44649.0 44649.0 44649.0 44649.0
Avg: 44649.0, Min: 44649.0, Max: 44649.0, Diff: 0.0]
[GC Worker (ms): 35.3 35.3 35.3 35.3 35.3 35.3 35.2 35.2
Avg: 35.3, Min: 35.2, Max: 35.3, Diff: 0.1]
[GC Worker Other (ms): 0.5 0.5 0.5 0.5 0.5 0.5 0.5 0.5
Avg: 0.5, Min: 0.5, Max: 0.5, Diff: 0.1]
[Clear CT: 0.1 ms]
[Other: 1.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.4 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.4 ms]
[Eden: 197M(197M)->0B(187M) Survivors: 19M->20M Heap: 431M(502M)->243M(502M)]
[Times: user=0.25 sys=0.00, real=0.04 secs]
46.029: [GC pause (young), 0.03551100 secs]
[Parallel Time: 34.2 ms]
[GC Worker Start (ms): 46028.7 46028.7 46028.7 46028.7 46028.8 46028.8 46028.8 46034.6
Avg: 46029.5, Min: 46028.7, Max: 46034.6, Diff: 5.9]
[Ext Root Scanning (ms): 2.3 2.3 2.9 3.2 2.8 3.1 3.1 0.0
Avg: 2.5, Min: 0.0, Max: 3.2, Diff: 3.2]
[Update RS (ms): 7.6 11.0 6.9 6.6 6.8 6.4 6.5 4.0
Avg: 7.0, Min: 4.0, Max: 11.0, Diff: 7.0]
[Processed Buffers : 12 6 27 11 12 17 13 20
Sum: 118, Avg: 14, Min: 6, Max: 27, Diff: 21]
[Scan RS (ms): 1.7 0.0 1.8 1.7 1.8 1.9 12.2 1.8
Avg: 2.8, Min: 0.0, Max: 12.2, Diff: 12.2]
[Object Copy (ms): 20.0 18.4 20.1 20.1 20.2 20.3 9.7 20.0
Avg: 18.6, Min: 9.7, Max: 20.3, Diff: 10.5]
[Termination (ms): 0.1 0.0 0.1 0.1 0.1 0.1 1.9 0.1
Avg: 0.3, Min: 0.0, Max: 1.9, Diff: 1.9]
[Termination Attempts : 11 1 9 10 11 11 6 12
Sum: 71, Avg: 8, Min: 1, Max: 12, Diff: 11]
[GC Worker End (ms): 46060.5 46060.5 46060.5 46060.5 46060.5 46060.5 46062.3 46060.5
Avg: 46060.7, Min: 46060.5, Max: 46062.3, Diff: 1.8]
[GC Worker (ms): 31.8 31.8 31.8 31.8 31.7 31.7 33.5 25.8
Avg: 31.2, Min: 25.8, Max: 33.5, Diff: 7.7]
[GC Worker Other (ms): 2.5 2.5 2.5 2.5 2.5 2.6 0.8 8.4
Avg: 3.0, Min: 0.8, Max: 8.4, Diff: 7.7]
[Clear CT: 0.1 ms]
[Other: 1.2 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.5 ms]
[Eden: 187M(187M)->0B(185M) Survivors: 20M->16M Heap: 430M(502M)->248M(502M)]
[Times: user=0.21 sys=0.00, real=0.04 secs]
2015-11-06T13:00:51,389 INFO [task-runner-0] io.druid.segment.realtime.plumber.RealtimePlumber - Submitting persist runnable for dataSource[MiddletiersBillingProd]
2015-11-06T13:00:51,390 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.realtime.plumber.RealtimePlumber - DataSource[MiddletiersBillingProd], Interval[2015-11-06T13:00:00.000Z/2015-11-06T14:00:00.000Z], persisting Hydrant[FireHydrant{index=io.druid.segment.incremental.OnheapIncrementalIndex@230f0be, queryable=io.druid.segment.ReferenceCountingSegment@5b0d4b11, count=1}]
2015-11-06T13:00:51,390 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting persist for interval[2015-11-06T13:00:00.000Z/2015-11-06T13:01:00.000Z], rows[75,000]
47.629: [GC pause (young) (initial-mark), 0.04239500 secs]
[Parallel Time: 41.2 ms]
[GC Worker Start (ms): 47629.4 47629.4 47629.4 47631.5 47639.5 47639.5 47639.5 47639.6
Avg: 47634.7, Min: 47629.4, Max: 47639.6, Diff: 10.2]
[Ext Root Scanning (ms): 5.5 5.3 6.2 4.4 0.0 0.0 0.0 0.0
Avg: 2.7, Min: 0.0, Max: 6.2, Diff: 6.2]
[Update RS (ms): 14.8 11.7 20.8 11.2 8.4 8.4 8.4 8.4
Avg: 11.5, Min: 8.4, Max: 20.8, Diff: 12.4]
[Processed Buffers : 6 6 11 21 25 20 17 20
Sum: 126, Avg: 15, Min: 6, Max: 25, Diff: 19]
[Scan RS (ms): 0.0 1.4 0.0 1.8 1.7 1.7 1.7 1.7
Avg: 1.3, Min: 0.0, Max: 1.8, Diff: 1.8]
[Object Copy (ms): 20.3 22.2 13.7 21.1 20.5 20.3 20.4 20.4
Avg: 19.9, Min: 13.7, Max: 22.2, Diff: 8.5]
[Termination (ms): 0.1 0.1 0.0 0.1 0.0 0.1 0.1 0.1
Avg: 0.1, Min: 0.0, Max: 0.1, Diff: 0.1]
[Termination Attempts : 13 18 1 18 1 23 14 13
Sum: 101, Avg: 12, Min: 1, Max: 23, Diff: 22]
[GC Worker End (ms): 47670.2 47670.2 47670.1 47670.2 47670.2 47670.2 47670.2 47670.2
Avg: 47670.2, Min: 47670.1, Max: 47670.2, Diff: 0.0]
[GC Worker (ms): 40.8 40.8 40.7 38.6 30.6 30.6 30.6 30.6
Avg: 35.4, Min: 30.6, Max: 40.8, Diff: 10.2]
[GC Worker Other (ms): 0.5 0.5 0.5 2.6 10.6 10.6 10.6 10.6
Avg: 5.8, Min: 0.5, Max: 10.6, Diff: 10.2]
[Clear CT: 0.2 ms]
[Other: 1.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.2 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.4 ms]
[Eden: 185M(185M)->0B(180M) Survivors: 16M->15M Heap: 433M(502M)->255M(502M)]
[Times: user=0.22 sys=0.00, real=0.04 secs]
47.672: [GC concurrent-root-region-scan-start]
47.689: [GC concurrent-root-region-scan-end, 0.0175630]
47.689: [GC concurrent-mark-start]
2015-11-06T13:00:51,673 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - outDir[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/1/v8-tmp] completed index.drd in 0 millis.
47.887: [GC concurrent-mark-end, 0.1978950 sec]
47.887: [GC remark 47.888: [GC ref-proc, 0.0000920 secs], 0.0061930 secs]
[Times: user=0.01 sys=0.00, real=0.00 secs]
47.894: [GC cleanup 306M->238M(502M), 0.0029520 secs]
[Times: user=0.01 sys=0.00, real=0.01 secs]
47.897: [GC concurrent-cleanup-start]
47.897: [GC concurrent-cleanup-end, 0.0002250]
2015-11-06T13:00:51,726 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - outDir[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/1/v8-tmp] completed dim conversions in 52 millis.
48.148: [GC pause (young), 0.03504400 secs]
[Parallel Time: 34.1 ms]
[GC Worker Start (ms): 48147.7 48147.7 48147.7 48150.7 48150.7 48150.7 48153.3 48155.2
Avg: 48150.5, Min: 48147.7, Max: 48155.2, Diff: 7.6]
[Ext Root Scanning (ms): 4.1 5.2 4.0 2.1 2.0 2.4 0.0 0.0
Avg: 2.5, Min: 0.0, Max: 5.2, Diff: 5.2]
[Update RS (ms): 9.1 13.1 8.9 8.2 12.8 7.6 7.5 5.6
Avg: 9.1, Min: 5.6, Max: 13.1, Diff: 7.5]
[Processed Buffers : 24 7 13 14 1 17 18 21
Sum: 115, Avg: 14, Min: 1, Max: 24, Diff: 23]
[Scan RS (ms): 0.5 0.0 0.8 0.7 0.0 0.9 0.9 0.9
Avg: 0.6, Min: 0.0, Max: 0.9, Diff: 0.9]
[Object Copy (ms): 19.8 15.2 19.9 19.5 15.7 19.6 19.5 19.4
Avg: 18.6, Min: 15.2, Max: 19.9, Diff: 4.7]
[Termination (ms): 0.1 0.1 0.1 0.1 0.0 0.1 0.0 0.1
Avg: 0.1, Min: 0.0, Max: 0.1, Diff: 0.1]
[Termination Attempts : 2 1 1 2 1 1 1 1
Sum: 10, Avg: 1, Min: 1, Max: 2, Diff: 1]
[GC Worker End (ms): 48181.3 48181.3 48181.3 48181.3 48181.3 48181.3 48181.3 48181.3
Avg: 48181.3, Min: 48181.3, Max: 48181.3, Diff: 0.0]
[GC Worker (ms): 33.6 33.7 33.6 30.6 30.6 30.6 28.0 26.1
Avg: 30.9, Min: 26.1, Max: 33.7, Diff: 7.6]
[GC Worker Other (ms): 0.4 0.4 0.4 3.4 3.4 3.4 6.1 8.0
Avg: 3.2, Min: 0.4, Max: 8.0, Diff: 7.6]
[Clear CT: 0.1 ms]
[Other: 0.9 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.3 ms]
[Eden: 180M(180M)->0B(80M) Survivors: 15M->20M Heap: 367M(502M)->197M(502M)]
[Times: user=0.22 sys=0.00, real=0.03 secs]
48.327: [GC pause (mixed), 0.03895800 secs]
[Parallel Time: 36.1 ms]
[GC Worker Start (ms): 48327.0 48327.0 48327.0 48327.0 48327.0 48327.0 48333.9 48333.9
Avg: 48328.7, Min: 48327.0, Max: 48333.9, Diff: 6.9]
[Ext Root Scanning (ms): 3.3 3.6 3.2 3.4 3.3 2.7 0.0 0.0
Avg: 2.4, Min: 0.0, Max: 3.6, Diff: 3.6]
[Update RS (ms): 7.6 11.5 7.8 10.9 11.5 8.5 4.3 4.4
Avg: 8.3, Min: 4.3, Max: 11.5, Diff: 7.2]
[Processed Buffers : 25 5 23 5 6 13 8 9
Sum: 94, Avg: 11, Min: 5, Max: 25, Diff: 20]
[Scan RS (ms): 0.8 0.0 0.8 0.0 0.0 0.4 0.7 0.7
Avg: 0.4, Min: 0.0, Max: 0.8, Diff: 0.8]
[Object Copy (ms): 23.1 19.7 23.0 20.4 20.0 23.1 22.9 22.8
Avg: 21.9, Min: 19.7, Max: 23.1, Diff: 3.4]
[Termination (ms): 0.1 0.0 0.1 0.1 0.1 0.1 0.1 0.9
Avg: 0.2, Min: 0.0, Max: 0.9, Diff: 0.9]
[Termination Attempts : 7 1 3 3 3 5 1 6
Sum: 29, Avg: 3, Min: 1, Max: 7, Diff: 6]
[GC Worker End (ms): 48361.9 48361.9 48361.9 48361.9 48361.9 48361.9 48361.9 48362.7
Avg: 48362.0, Min: 48361.9, Max: 48362.7, Diff: 0.9]
[GC Worker (ms): 34.9 34.9 34.9 34.9 34.9 34.8 28.0 28.8
Avg: 33.2, Min: 28.0, Max: 34.9, Diff: 6.9]
[GC Worker Other (ms): 1.3 1.3 1.3 1.3 1.3 1.3 8.2 7.3
Avg: 2.9, Min: 1.3, Max: 8.2, Diff: 6.9]
[Clear CT: 0.1 ms]
[Other: 2.7 ms]
[Choose CSet: 0.1 ms]
[Ref Proc: 2.1 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.3 ms]
[Eden: 80M(80M)->0B(92M) Survivors: 20M->8192K Heap: 277M(502M)->153M(502M)]
[Times: user=0.24 sys=0.00, real=0.04 secs]
48.543: [GC pause (mixed), 0.05091100 secs]
[Parallel Time: 49.9 ms]
[GC Worker Start (ms): 48542.8 48542.8 48542.8 48545.4 48545.4 48545.5 48545.5 48545.5
Avg: 48544.5, Min: 48542.8, Max: 48545.5, Diff: 2.7]
[Ext Root Scanning (ms): 3.9 3.8 4.3 7.6 7.7 1.1 2.1 1.2
Avg: 4.0, Min: 1.1, Max: 7.7, Diff: 6.5]
[Update RS (ms): 7.3 7.0 16.5 1.1 0.6 7.1 11.3 7.0
Avg: 7.2, Min: 0.6, Max: 16.5, Diff: 15.9]
[Processed Buffers : 15 17 9 2 1 20 8 14
Sum: 86, Avg: 10, Min: 1, Max: 20, Diff: 19]
[Scan RS (ms): 14.8 14.6 4.3 15.8 14.6 20.4 14.3 15.0
Avg: 14.2, Min: 4.3, Max: 20.4, Diff: 16.1]
[Object Copy (ms): 20.7 21.3 21.5 19.7 21.1 15.3 16.2 20.9
Avg: 19.6, Min: 15.3, Max: 21.5, Diff: 6.1]
[Termination (ms): 0.1 0.1 0.1 0.0 0.1 2.8 0.1 0.0
Avg: 0.4, Min: 0.0, Max: 2.8, Diff: 2.8]
[Termination Attempts : 1 1 1 1 1 1 1 1
Sum: 8, Avg: 1, Min: 1, Max: 1, Diff: 0]
[GC Worker End (ms): 48589.6 48589.6 48589.6 48589.6 48589.6 48592.2 48589.6 48589.5
Avg: 48589.9, Min: 48589.5, Max: 48592.2, Diff: 2.7]
[GC Worker (ms): 46.8 46.8 46.7 44.1 44.1 46.7 44.0 44.0
Avg: 45.4, Min: 44.0, Max: 46.8, Diff: 2.8]
[GC Worker Other (ms): 3.1 3.1 3.1 5.7 5.8 3.2 5.8 5.9
Avg: 4.5, Min: 3.1, Max: 5.9, Diff: 2.7]
[Clear CT: 0.1 ms]
[Other: 0.9 ms]
[Choose CSet: 0.1 ms]
[Ref Proc: 0.2 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.3 ms]
[Eden: 92M(92M)->0B(284M) Survivors: 8192K->7168K Heap: 245M(502M)->138M(502M)]
[Times: user=0.27 sys=0.00, real=0.05 secs]
49.247: [GC pause (young), 0.03659800 secs]
[Parallel Time: 29.9 ms]
[GC Worker Start (ms): 49247.3 49247.3 49247.3 49254.5 49254.5 49254.5 49254.5 49254.6
Avg: 49251.8, Min: 49247.3, Max: 49254.6, Diff: 7.3]
[Ext Root Scanning (ms): 5.0 5.7 5.7 0.0 0.0 0.0 0.0 0.0
Avg: 2.1, Min: 0.0, Max: 5.7, Diff: 5.7]
[Update RS (ms): 8.2 16.6 7.4 6.3 5.0 15.1 6.3 7.7
Avg: 9.1, Min: 5.0, Max: 16.6, Diff: 11.6]
[Processed Buffers : 23 6 12 15 11 9 24 3
Sum: 103, Avg: 12, Min: 3, Max: 24, Diff: 21]
[Scan RS (ms): 0.3 0.0 0.3 0.3 0.3 0.0 0.3 0.0
Avg: 0.2, Min: 0.0, Max: 0.3, Diff: 0.3]
[Object Copy (ms): 15.4 6.5 15.5 14.9 14.9 6.4 14.9 14.0
Avg: 12.8, Min: 6.4, Max: 15.5, Diff: 9.1]
[Termination (ms): 0.1 0.1 0.0 0.1 0.1 0.1 0.3 0.0
Avg: 0.1, Min: 0.0, Max: 0.3, Diff: 0.3]
[Termination Attempts : 6 7 1 5 6 12 5 1
Sum: 43, Avg: 5, Min: 1, Max: 12, Diff: 11]
[GC Worker End (ms): 49276.2 49276.2 49276.2 49276.2 49276.2 49276.2 49276.4 49276.2
Avg: 49276.2, Min: 49276.2, Max: 49276.4, Diff: 0.2]
[GC Worker (ms): 29.0 28.9 28.9 21.7 21.7 21.7 21.9 21.6
Avg: 24.4, Min: 21.6, Max: 29.0, Diff: 7.3]
[GC Worker Other (ms): 1.0 1.0 1.0 8.2 9.6 8.3 8.1 8.3
Avg: 5.7, Min: 1.0, Max: 9.6, Diff: 8.6]
[Clear CT: 0.2 ms]
[Other: 6.5 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 5.7 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.7 ms]
[Eden: 284M(284M)->0B(275M) Survivors: 7168K->18M Heap: 422M(502M)->149M(502M)]
[Times: user=0.20 sys=0.00, real=0.03 secs]
2015-11-06T13:00:53,258 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - outDir[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/1/v8-tmp] completed walk through of 75,000 rows in 1,532 millis.
2015-11-06T13:00:53,258 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[adid] with cardinality[1,663]
2015-11-06T13:00:53,306 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[adid] in 48 millis.
2015-11-06T13:00:53,307 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[age] with cardinality[8]
2015-11-06T13:00:53,317 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[age] in 11 millis.
2015-11-06T13:00:53,317 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[billingType] with cardinality[7]
2015-11-06T13:00:53,323 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[billingType] in 6 millis.
2015-11-06T13:00:53,323 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[city] with cardinality[36]
2015-11-06T13:00:53,349 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[city] in 26 millis.
2015-11-06T13:00:53,349 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[dsp] with cardinality[6]
2015-11-06T13:00:53,353 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[dsp] in 4 millis.
2015-11-06T13:00:53,353 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[education] with cardinality[0]
2015-11-06T13:00:53,354 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[education] in 1 millis.
2015-11-06T13:00:53,354 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expAppId] with cardinality[6]
2015-11-06T13:00:53,359 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expAppId] in 5 millis.
2015-11-06T13:00:53,359 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer1] with cardinality[10]
2015-11-06T13:00:53,363 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer1] in 4 millis.
2015-11-06T13:00:53,363 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer2] with cardinality[4]
2015-11-06T13:00:53,367 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer2] in 4 millis.
2015-11-06T13:00:53,367 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer3] with cardinality[3]
2015-11-06T13:00:53,370 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer3] in 3 millis.
2015-11-06T13:00:53,370 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer4] with cardinality[6]
2015-11-06T13:00:53,375 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer4] in 5 millis.
2015-11-06T13:00:53,375 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer5] with cardinality[6]
2015-11-06T13:00:53,380 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer5] in 5 millis.
2015-11-06T13:00:53,381 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer6] with cardinality[3]
2015-11-06T13:00:53,386 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer6] in 6 millis.
2015-11-06T13:00:53,386 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer7] with cardinality[2]
2015-11-06T13:00:53,391 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer7] in 5 millis.
2015-11-06T13:00:53,392 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[expLayer8] with cardinality[2]
2015-11-06T13:00:53,397 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[expLayer8] in 5 millis.
2015-11-06T13:00:53,397 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[experimentId] with cardinality[44]
2015-11-06T13:00:53,403 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[experimentId] in 6 millis.
2015-11-06T13:00:53,403 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[gender] with cardinality[3]
2015-11-06T13:00:53,422 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[gender] in 19 millis.
2015-11-06T13:00:53,422 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[incomeLevel] with cardinality[0]
2015-11-06T13:00:53,422 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[incomeLevel] in 0 millis.
2015-11-06T13:00:53,423 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[mediaType] with cardinality[22]
2015-11-06T13:00:53,442 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[mediaType] in 20 millis.
2015-11-06T13:00:53,442 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[pageId] with cardinality[88]
2015-11-06T13:00:53,447 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[pageId] in 5 millis.
2015-11-06T13:00:53,448 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[platform] with cardinality[5]
2015-11-06T13:00:53,451 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[platform] in 4 millis.
2015-11-06T13:00:53,451 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[posId] with cardinality[4]
2015-11-06T13:00:53,454 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[posId] in 3 millis.
2015-11-06T13:00:53,454 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[province] with cardinality[35]
2015-11-06T13:00:53,482 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[province] in 28 millis.
2015-11-06T13:00:53,482 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[refType] with cardinality[3]
2015-11-06T13:00:53,485 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[refType] in 3 millis.
2015-11-06T13:00:53,485 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[reqType] with cardinality[4]
2015-11-06T13:00:53,490 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[reqType] in 5 millis.
2015-11-06T13:00:53,490 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[sessionId] with cardinality[28]
2015-11-06T13:00:53,492 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[sessionId] in 2 millis.
2015-11-06T13:00:53,492 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[tagId] with cardinality[42]
2015-11-06T13:00:53,496 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[tagId] in 4 millis.
2015-11-06T13:00:53,496 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Starting dimension[templateId] with cardinality[19]
2015-11-06T13:00:53,500 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - Completed dimension[templateId] in 4 millis.
2015-11-06T13:00:53,501 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexMerger - outDir[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/1/v8-tmp] completed inverted.drd in 243 millis.
2015-11-06T13:00:53,520 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Converting v8[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/1/v8-tmp] to v9[/home/work/app/druid/logs/persistent/task/index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0/work/persist/MiddletiersBillingProd/2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z/1]
2015-11-06T13:00:53,521 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_adid.drd]
2015-11-06T13:00:53,537 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[adid] is single value, converting…
2015-11-06T13:00:53,550 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_age.drd]
2015-11-06T13:00:53,560 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[age] is single value, converting…
2015-11-06T13:00:53,580 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_billingType.drd]
2015-11-06T13:00:53,593 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[billingType] is single value, converting…
2015-11-06T13:00:53,593 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[billingType] has null rows.
2015-11-06T13:00:53,605 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_city.drd]
2015-11-06T13:00:53,616 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[city] is single value, converting…
2015-11-06T13:00:53,616 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[city] has null rows.
2015-11-06T13:00:53,630 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_dsp.drd]
2015-11-06T13:00:53,644 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[dsp] is single value, converting…
2015-11-06T13:00:53,644 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[dsp] has null rows.
2015-11-06T13:00:53,659 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_education.drd]
2015-11-06T13:00:53,660 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[education] had cardinality 0, equivalent to no column, so skipping.
2015-11-06T13:00:53,660 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expAppId.drd]
2015-11-06T13:00:53,684 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expAppId] is single value, converting…
2015-11-06T13:00:53,684 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expAppId] has null rows.
49.889: [GC pause (young), 0.02743800 secs]
[Parallel Time: 26.2 ms]
[GC Worker Start (ms): 49889.3 49889.3 49889.4 49889.4 49889.4 49895.3 49895.3 49895.3
Avg: 49891.6, Min: 49889.3, Max: 49895.3, Diff: 5.9]
[Ext Root Scanning (ms): 4.2 3.7 4.3 3.7 4.3 0.0 0.0 0.0
Avg: 2.5, Min: 0.0, Max: 4.3, Diff: 4.3]
[Update RS (ms): 11.8 12.4 12.4 1.9 1.1 0.0 0.0 0.0
Avg: 5.0, Min: 0.0, Max: 12.4, Diff: 12.4]
[Processed Buffers : 7 6 4 16 11 1 0 0
Sum: 45, Avg: 5, Min: 0, Max: 16, Diff: 16]
[Scan RS (ms): 0.0 0.0 0.0 0.1 0.1 0.1 0.1 0.1
Avg: 0.1, Min: 0.0, Max: 0.1, Diff: 0.1]
[Object Copy (ms): 7.9 7.6 7.2 19.9 18.2 17.7 17.7 17.8
Avg: 14.3, Min: 7.2, Max: 19.9, Diff: 12.8]
[Termination (ms): 1.8 1.9 1.8 0.0 1.9 1.9 1.9 1.8
Avg: 1.6, Min: 0.0, Max: 1.9, Diff: 1.9]
[Termination Attempts : 1 1 6 1 11 1 9 1
Sum: 31, Avg: 3, Min: 1, Max: 11, Diff: 10]
[GC Worker End (ms): 49915.1 49915.0 49915.1 49915.0 49915.1 49915.0 49915.1 49915.0
Avg: 49915.1, Min: 49915.0, Max: 49915.1, Diff: 0.0]
[GC Worker (ms): 25.7 25.7 25.7 25.7 25.7 19.8 19.8 19.8
Avg: 23.5, Min: 19.8, Max: 25.7, Diff: 6.0]
[GC Worker Other (ms): 0.5 0.5 0.5 0.5 0.5 6.4 6.4 6.4
Avg: 2.7, Min: 0.5, Max: 6.4, Diff: 5.9]
[Clear CT: 0.1 ms]
[Other: 1.1 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.5 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.4 ms]
[Eden: 275M(275M)->0B(275M) Survivors: 18M->21M Heap: 424M(502M)->152M(502M)]
[Times: user=0.16 sys=0.00, real=0.03 secs]
2015-11-06T13:00:53,726 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer1.drd]
2015-11-06T13:00:53,740 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer1] is single value, converting…
2015-11-06T13:00:53,740 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer1] has null rows.
2015-11-06T13:00:53,754 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer2.drd]
2015-11-06T13:00:53,767 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer2] is single value, converting…
2015-11-06T13:00:53,767 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer2] has null rows.
2015-11-06T13:00:53,781 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer3.drd]
2015-11-06T13:00:53,794 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer3] is single value, converting…
2015-11-06T13:00:53,794 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer3] has null rows.
2015-11-06T13:00:53,809 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer4.drd]
2015-11-06T13:00:53,823 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer4] is single value, converting…
2015-11-06T13:00:53,823 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer4] has null rows.
2015-11-06T13:00:53,837 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer5.drd]
2015-11-06T13:00:53,850 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer5] is single value, converting…
2015-11-06T13:00:53,850 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer5] has null rows.
2015-11-06T13:00:53,863 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer6.drd]
2015-11-06T13:00:53,876 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer6] is single value, converting…
2015-11-06T13:00:53,877 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer6] has null rows.
2015-11-06T13:00:53,890 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer7.drd]
2015-11-06T13:00:53,903 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer7] is single value, converting…
2015-11-06T13:00:53,904 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer7] has null rows.
2015-11-06T13:00:53,919 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_expLayer8.drd]
2015-11-06T13:00:53,932 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer8] is single value, converting…
2015-11-06T13:00:53,932 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[expLayer8] has null rows.
2015-11-06T13:00:53,947 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_experimentId.drd]
2015-11-06T13:00:53,961 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[experimentId] is single value, converting…
2015-11-06T13:00:53,961 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[experimentId] has null rows.
2015-11-06T13:00:53,979 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_gender.drd]
2015-11-06T13:00:53,992 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[gender] is single value, converting…
2015-11-06T13:00:54,019 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_incomeLevel.drd]
2015-11-06T13:00:54,019 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[incomeLevel] had cardinality 0, equivalent to no column, so skipping.
2015-11-06T13:00:54,019 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_mediaType.drd]
50.218: [GC pause (young), 0.03425300 secs]
[Parallel Time: 33.2 ms]
[GC Worker Start (ms): 50218.2 50218.2 50218.3 50218.3 50228.5 50228.5 50228.5 50228.6
Avg: 50223.4, Min: 50218.2, Max: 50228.6, Diff: 10.3]
[Ext Root Scanning (ms): 4.1 4.8 4.6 4.4 0.0 0.0 0.0 0.0
Avg: 2.2, Min: 0.0, Max: 4.8, Diff: 4.7]
[Update RS (ms): 2.3 1.4 1.4 1.9 0.0 0.0 0.0 0.0
Avg: 0.9, Min: 0.0, Max: 2.3, Diff: 2.3]
[Processed Buffers : 8 13 3 8 0 0 0 0
Sum: 32, Avg: 4, Min: 0, Max: 13, Diff: 13]
[Scan RS (ms): 0.1 0.1 0.1 0.1 0.0 0.0 0.0 0.0
Avg: 0.1, Min: 0.0, Max: 0.1, Diff: 0.1]
[Object Copy (ms): 18.3 19.0 18.5 18.3 14.5 14.4 14.4 22.4
Avg: 17.5, Min: 14.4, Max: 22.4, Diff: 8.1]
[Termination (ms): 8.1 7.5 8.1 8.1 8.0 8.1 8.1 0.0
Avg: 7.0, Min: 0.0, Max: 8.1, Diff: 8.1]
[Termination Attempts : 1 1 14 19 4 7 12 10
Sum: 68, Avg: 8, Min: 1, Max: 19, Diff: 18]
[GC Worker End (ms): 50251.0 50251.0 50251.0 50251.0 50251.0 50251.0 50251.0 50251.0
Avg: 50251.0, Min: 50251.0, Max: 50251.0, Diff: 0.0]
[GC Worker (ms): 32.8 32.8 32.8 32.8 22.5 22.5 22.5 22.5
Avg: 27.6, Min: 22.5, Max: 32.8, Diff: 10.3]
[GC Worker Other (ms): 0.5 0.5 0.5 0.5 10.8 10.8 10.8 10.8
Avg: 5.6, Min: 0.5, Max: 10.8, Diff: 10.3]
[Clear CT: 0.2 ms]
[Other: 0.9 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.4 ms]
[Eden: 275M(275M)->0B(277M) Survivors: 21M->19M Heap: 427M(502M)->154M(502M)]
[Times: user=0.20 sys=0.00, real=0.03 secs]
2015-11-06T13:00:54,069 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[mediaType] is single value, converting…
2015-11-06T13:00:54,091 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_pageId.drd]
2015-11-06T13:00:54,112 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[pageId] is single value, converting…
2015-11-06T13:00:54,112 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[pageId] has null rows.
2015-11-06T13:00:54,125 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_platform.drd]
2015-11-06T13:00:54,138 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[platform] is single value, converting…
2015-11-06T13:00:54,138 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[platform] has null rows.
2015-11-06T13:00:54,152 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_posId.drd]
2015-11-06T13:00:54,170 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[posId] is single value, converting…
2015-11-06T13:00:54,170 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[posId] has null rows.
2015-11-06T13:00:54,195 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_province.drd]
2015-11-06T13:00:54,197 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[province] is single value, converting…
2015-11-06T13:00:54,208 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_refType.drd]
2015-11-06T13:00:54,211 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[refType] is single value, converting…
2015-11-06T13:00:54,211 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[refType] has null rows.
2015-11-06T13:00:54,224 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_reqType.drd]
2015-11-06T13:00:54,227 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[reqType] is single value, converting…
2015-11-06T13:00:54,227 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[reqType] has null rows.
2015-11-06T13:00:54,240 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_sessionId.drd]
2015-11-06T13:00:54,242 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[sessionId] is single value, converting…
2015-11-06T13:00:54,243 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[sessionId] has null rows.
2015-11-06T13:00:54,254 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_tagId.drd]
2015-11-06T13:00:54,257 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[tagId] is single value, converting…
2015-11-06T13:00:54,257 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[tagId] has null rows.
2015-11-06T13:00:54,269 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[dim_templateId.drd]
2015-11-06T13:00:54,272 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[templateId] is single value, converting…
2015-11-06T13:00:54,272 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Dimension[templateId] has null rows.
2015-11-06T13:00:54,283 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[index.drd]
2015-11-06T13:00:54,284 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[inverted.drd]
2015-11-06T13:00:54,284 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_click_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,284 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_count_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,284 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_endDownload_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,284 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_endInstall_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,285 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_expose_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,285 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_fee_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,285 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_loaded_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,285 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_queryFailed_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,286 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_query_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,286 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_startDownload_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,286 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[met_startInstall_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,286 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[spatial.drd]
2015-11-06T13:00:54,286 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Processing file[time_LITTLE_ENDIAN.drd]
2015-11-06T13:00:54,287 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.IndexIO$DefaultIndexIOHandler - Skipped files[[index.drd, inverted.drd, spatial.drd]]
2015-11-06T13:00:54,292 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.ReferenceCountingSegment - Closing MiddletiersBillingProd_2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z_2015-11-06T13:00:12.828Z
2015-11-06T13:00:54,292 INFO [MiddletiersBillingProd-incremental-persist] io.druid.segment.ReferenceCountingSegment - Closing MiddletiersBillingProd_2015-11-06T13:00:00.000Z_2015-11-06T14:00:00.000Z_2015-11-06T13:00:12.828Z, numReferences: 0
50.713: [GC pause (young), 0.02309700 secs]

Hey Xuehui,

It looks like this is a pretty short snippet of the log. It’s not clear from this snippet what exactly is going wrong. But, some common reasons for handoff to not work are listed on http://druid.io/docs/latest/ingestion/faq.html under “My realtime node is not handing segments off”.

Another thing to look for is whether your task has had an error in an important thread. OOME is the most common one that causes problems here, and can be addressed by adjusting your tunings (the big ones are heap size, maxRowsInMemory, and maxPendingPersists).

Yes, I can see some OOME in the log, like below.

The max heap size of worker/peons is 2g, while maxRowsInMemory, maxPendingPersists are both default value, since I don’t how to config them in tranquility.

Now I get two stuck tasks for the same OOME error.

Please help to get rid of this kind of error, thanks in advance!

index_realtime_MiddletiersBillingProd_2015-11-06T21:00:00.000+08:00_0_0
index_realtime_MiddletiersBillingProd_2015-11-10T20:00:00.000+08:00_0_0

Parts of runtime properties of middle manager:

Resources for peons

druid.indexer.runner.javaOpts=-server -Xmx2g -XX:+UseG1GC -XX:MaxGCPauseMillis=100 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps

The tunningConfig of the task:

“tuningConfig”: {

“type”: “realtime”,

“maxRowsInMemory”: 75000,

“intermediatePersistPeriod”: “PT10M”,

“windowPeriod”: “PT55M”,

“basePersistDirectory”: “/tmp/1445954405928-0”,

“versioningPolicy”: {

“type”: “intervalStart”

},

“rejectionPolicy”: {

“type”: “none”

},

“maxPendingPersists”: 0,

“shardSpec”: {

“type”: “linear”,

“partitionNum”: 0

},

“indexSpec”: {

“bitmap”: {

“type”: “concise”

},

“dimensionCompression”: null,

“metricCompression”: null

},

“persistInHeap”: false,

“ingestOffheap”: false,

“bufferSize”: 134217728

}

OOME log:

7200.637: [Full GC (System.gc()) 1135M->195M(651M), 0.5430150 secs]
 [Times: user=0.58 sys=0.00, real=0.54 secs]
Exception in thread "plumber_merge_0" java.lang.OutOfMemoryError: Direct buffer memory
	at java.nio.Bits.reserveMemory(Bits.java:658)
	at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:123)
	at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:306)
	at io.druid.segment.CompressedPools$4.get(CompressedPools.java:98)
	at io.druid.segment.CompressedPools$4.get(CompressedPools.java:91)
	at io.druid.collections.StupidPool.take(StupidPool.java:53)
	at io.druid.segment.CompressedPools.getByteBuf(CompressedPools.java:106)
	at io.druid.segment.data.CompressedObjectStrategy.fromByteBuffer(CompressedObjectStrategy.java:284)
	at io.druid.segment.data.CompressedObjectStrategy.fromByteBuffer(CompressedObjectStrategy.java:40)
	at io.druid.segment.data.GenericIndexed$BufferIndexed._get(GenericIndexed.java:221)
	at io.druid.segment.data.GenericIndexed$1.get(GenericIndexed.java:296)
	at io.druid.segment.data.CompressedVSizeIntsIndexedSupplier$CompressedVSizeIndexedInts.loadBuffer(CompressedVSizeIntsIndexedSupplier.java:383)
	at io.druid.segment.data.CompressedVSizeIntsIndexedSupplier$CompressedVSizeIndexedInts.get(CompressedVSizeIntsIndexedSupplier.java:344)
	at io.druid.segment.column.SimpleDictionaryEncodedColumn.getSingleValueRow(SimpleDictionaryEncodedColumn.java:62)
	at io.druid.segment.QueryableIndexIndexableAdapter$2$1.next(QueryableIndexIndexableAdapter.java:252)
	at io.druid.segment.QueryableIndexIndexableAdapter$2$1.next(QueryableIndexIndexableAdapter.java:172)
	at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48)
	at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48)
	at com.google.common.collect.Iterators$PeekingImpl.peek(Iterators.java:1162)
	at com.metamx.common.guava.MergeIterator$1.compare(MergeIterator.java:46)
	at com.metamx.common.guava.MergeIterator$1.compare(MergeIterator.java:42)
	at java.util.PriorityQueue.siftUpUsingComparator(PriorityQueue.java:649)
	at java.util.PriorityQueue.siftUp(PriorityQueue.java:627)
	at java.util.PriorityQueue.offer(PriorityQueue.java:329)
	at java.util.PriorityQueue.add(PriorityQueue.java:306)
	at com.metamx.common.guava.MergeIterator.<init>(MergeIterator.java:55)
	at com.metamx.common.guava.MergeIterable.iterator(MergeIterable.java:49)
	at io.druid.collections.CombiningIterable.iterator(CombiningIterable.java:93)
	at io.druid.segment.IndexMerger.makeIndexFiles(IndexMerger.java:730)
	at io.druid.segment.IndexMerger.merge(IndexMerger.java:336)
	at io.druid.segment.IndexMerger.mergeQueryableIndex(IndexMerger.java:218)
	at io.druid.segment.IndexMerger.mergeQueryableIndex(IndexMerger.java:207)
	at io.druid.segment.realtime.plumber.RealtimePlumber$4.doRun(RealtimePlumber.java:446)
	at io.druid.common.guava.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:40)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:722)

在 2015年11月11日星期三 UTC+8上午10:56:06,Gian Merlino写道:

Hey Xuehui,

You should be able to avoid this by setting -XX:MaxDirectMemorySize higher (in your druid.indexer.runner.javaOpts). But, I’m also wondering if there are some unexpected buffers being allocated. Could you attach full logs from this task? Also, what have you set for druid.processing.buffer.sizeBytes and druid.processing.numThreads on your middleManagers/peons?

The log is 160MB, cannot upload it as attachment. Can I sent it to you mail box or somewhere else?
Attachment is the task json file and middle manager runtimes.properties file.

在 2015年11月12日星期四 UTC+8上午9:27:24,Gian Merlino写道:

task.json (2.53 KB)

runtime.properties (2.09 KB)

Hi Gian,

I’ve share full log of the task at OneDrive, here is the link: https://onedrive.live.com/redir?resid=F64A0497254B08B!251587&authkey=!AIyKhZquS09Bu30&ithint=file%2C

For these “java.lang.OutOfMemoryError: Direct buffer memory” realtime tasks, how to get the memory data handed off to historical nodes successfully?

Thanks,

Xuehui

在 2015年11月12日星期四 UTC+8下午2:50:21,Xuehui Chen写道:

Hey, I know it might be too long ago to remember, but by any chance to u know what did u do to fix this and make the task successfully hand over?

It is likely that the historical node can’t keep up with. My experience was that many indexing tasks were running or pending on the middle manager nodes while the historical node became unresponsive. Once the historical node recovers, the issue gets fixed.