# Mapper turns out to be very slow

**URL:** <https://discuss.elastic.co/t/mapper-turns-out-to-be-very-slow/131877>\
**Category:** Elasticsearch\
**Tags:** es-hadoop\
**Created:** [May 15, 2018, 7:52am UTC](https://discuss.elastic.co/t/mapper-turns-out-to-be-very-slow/131877 "2018-05-15T07:52:37Z")\
**Posts on this page:** 8\
**Page:** 1

<div class="post-metadata">

**Author:** ![machong](https://avatars.discourse-cdn.com/v4/letter/m/35a633/32.png) [@machong](https://discuss.elastic.co/u/machong)\
**Post date:** [May 15, 2018, 7:52am UTC](https://discuss.elastic.co/t/mapper-turns-out-to-be-very-slow/131877/1 "2018-05-15T07:52:37Z")

</div>

I'm using eshadoop lib to do some data process work. the hadoop application seems to get stuck when the mapper progress reached 80%. I tried to add some debug message into mapper and found that the program is not blocked nor has any error but just running very slow(too slow to bear).

I found below message in GC Log（elasticsearch）, it guess it has some kind of correlation with this problem.

{Heap before GC invocations=0 (full 1):  
par new generation total 18874368K, used 16777216K [0x0000000180000000, 0x0000000680000000, 0x0000000680000000)  
eden space 16777216K, 100% used [0x0000000180000000, 0x0000000580000000, 0x0000000580000000)  
from space 2097152K, 0% used [0x0000000580000000, 0x0000000580000000, 0x0000000600000000)  
to space 2097152K, 0% used [0x0000000600000000, 0x0000000600000000, 0x0000000680000000)  
concurrent mark-sweep generation total 5242880K, used 0K [0x0000000680000000, 0x00000007c0000000, 0x00000007c0000000)  
Metaspace used 59486K, capacity 64396K, committed 64456K, reserved 1103872K  
class space used 8006K, capacity 9715K, committed 9768K, reserved 1048576K  
2018-05-15T15:18:43.846+0800: 14.899: [GC (Allocation Failure) 2018-05-15T15:18:43.846+0800: 14.899: [ParNew  
Desired survivor size 1073741824 bytes, new threshold 15 (max 15)

- age 1: 261086432 bytes, 261086432 total  
: 16777216K-\>255372K(18874368K), 0.1813307 secs] 16777216K-\>255372K(24117248K), 0.1814428 secs] [Times: user=1.30 sys=0.26, real=0.18 secs]

any one can help to give some suggestion ?

---

<div class="post-metadata">

**Author:** ![machong](https://avatars.discourse-cdn.com/v4/letter/m/35a633/32.png) [@machong](https://discuss.elastic.co/u/machong)\
**Post date:** [May 15, 2018, 7:59am UTC](https://discuss.elastic.co/t/mapper-turns-out-to-be-very-slow/131877/2 "2018-05-15T07:59:10Z")

</div>

> [@machong](#):
>
> c

By the way, i'v try to enlarged the jvm heap of Elasticsearch to 25g, but it did't help

---

<div class="post-metadata">

**Author:** ![james.baiera](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/james.baiera/32/10209_2.png) [@james.baiera](https://discuss.elastic.co/u/james.baiera)\
**Post date:** [May 16, 2018, 6:31pm UTC](https://discuss.elastic.co/t/mapper-turns-out-to-be-very-slow/131877/3 "2018-05-16T18:31:06Z")

</div>

Can you perform a heap dump? Perhaps that can highlight what is taking up all the space in eden

---

<div class="post-metadata">

**Author:** ![machong](https://avatars.discourse-cdn.com/v4/letter/m/35a633/32.png) [@machong](https://discuss.elastic.co/u/machong)\
**Post date:** [May 17, 2018, 3:48am UTC](https://discuss.elastic.co/t/mapper-turns-out-to-be-very-slow/131877/4 "2018-05-17T03:48:14Z")

</div>

heap dump as below, occupancy rate of eden space is not very high, but at this time the mapper get to run in rather too slow speed when the progress reaches 80 percentage.

S0 S1 E O M CCS YGC YGCT FGC FGCT GCT  
0.00 2.41 10.01 44.25 91.94 82.60 47 5.440 2 0.619 6.059  
0.00 2.41 10.88 44.25 91.94 82.60 47 5.440 2 0.619 6.059  
0.00 2.41 11.27 44.25 91.94 82.60 47 5.440 2 0.619 6.059  
0.00 2.41 12.11 44.25 91.94 82.60 47 5.440 2 0.619 6.059  
0.00 2.41 13.27 44.25 91.94 82.60 47 5.440 2 0.619 6.059  
0.00 2.41 14.92 44.25 91.94 82.60 47 5.440 2 0.619 6.059  
0.00 2.41 16.30 44.25 91.94 82.60 47 5.440 2 0.619 6.059  
0.00 2.41 18.09 44.25 91.94 82.60 47 5.440 2 0.619 6.059  
0.00 2.41 19.75 44.25 91.94 82.60 47 5.440 2 0.619 6.059

Hadoop app console out:

2018-05-17 11:41:44,767 INFO mapreduce.Job: Running job: job\_1526364289182\_0011  
2018-05-17 11:41:51,941 INFO mapreduce.Job: Job job\_1526364289182\_0011 running in uber mode : false  
2018-05-17 11:41:51,943 INFO mapreduce.Job: map 0% reduce 0%  
2018-05-17 11:42:04,125 INFO mapreduce.Job: map 4% reduce 0%  
2018-05-17 11:42:05,147 INFO mapreduce.Job: map 10% reduce 0%  
2018-05-17 11:42:06,157 INFO mapreduce.Job: map 14% reduce 0%  
2018-05-17 11:42:07,166 INFO mapreduce.Job: map 20% reduce 0%  
2018-05-17 11:42:08,173 INFO mapreduce.Job: map 34% reduce 0%  
2018-05-17 11:42:09,179 INFO mapreduce.Job: map 56% reduce 0%  
2018-05-17 11:42:10,187 INFO mapreduce.Job: map 80% reduce 0%  
2018-05-17 11:42:24,265 INFO mapreduce.Job: map 80% reduce 27%

---

<div class="post-metadata">

**Author:** ![machong](https://avatars.discourse-cdn.com/v4/letter/m/35a633/32.png) [@machong](https://discuss.elastic.co/u/machong)\
**Post date:** [May 17, 2018, 5:43am UTC](https://discuss.elastic.co/t/mapper-turns-out-to-be-very-slow/131877/5 "2018-05-17T05:43:38Z")

</div>

add a piece of jstack dump for reference:  
"elasticsearch[node-1][search][T#3]" #144 daemon prio=5 os\_prio=0 tid=0x00007f0e6c015ef0 nid=0x33ea4 runnable [0x00007f0e5811f000]  
java.lang.Thread.State: RUNNABLE  
at org.apache.lucene.codecs.blocktree.SegmentTermsEnum.postings(SegmentTermsEnum.java:998)  
at org.elasticsearch.search.slice.TermsSliceQuery.build(TermsSliceQuery.java:87)  
at org.elasticsearch.search.slice.TermsSliceQuery.access$000(TermsSliceQuery.java:49)  
at org.elasticsearch.search.slice.TermsSliceQuery$1.scorer(TermsSliceQuery.java:62)  
at org.apache.lucene.search.Weight.scorerSupplier(Weight.java:113)  
at org.apache.lucene.search.BooleanWeight.scorerSupplier(BooleanWeight.java:329)  
at org.apache.lucene.search.BooleanWeight.scorerSupplier(BooleanWeight.java:329)  
at org.apache.lucene.search.BooleanWeight.scorer(BooleanWeight.java:295)  
at org.apache.lucene.search.Weight.bulkScorer(Weight.java:147)  
at org.apache.lucene.search.BooleanWeight.bulkScorer(BooleanWeight.java:289)  
at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:657)  
at org.elasticsearch.search.internal.ContextIndexSearcher.search(ContextIndexSearcher.java:191)  
at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:462)  
at org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:265)  
at org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:107)  
at org.elasticsearch.search.SearchService.executeFetchPhase(SearchService.java:466)  
at org.elasticsearch.action.search.SearchTransportService$9.messageReceived(SearchTransportService.java:424)  
at org.elasticsearch.action.search.SearchTransportService$9.messageReceived(SearchTransportService.java:421)  
at org.elasticsearch.xpack.security.transport.SecurityServerTransportInterceptor$ProfileSecuredRequestHandler$1.doRun(SecurityServerTransportInterceptor.java:258)  
at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)  
at org.elasticsearch.xpack.security.transport.SecurityServerTransportInterceptor$ProfileSecuredRequestHandler.messageReceived(SecurityServerTransportInterceptor.java:316)  
at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:66)  
at org.elasticsearch.transport.TransportService$7.doRun(TransportService.java:656)  
at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:635)  
at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)  
at org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:41)  
at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)  
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)  
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)  
at java.lang.Thread.run(Thread.java:748)

---

<div class="post-metadata">

**Author:** ![machong](https://avatars.discourse-cdn.com/v4/letter/m/35a633/32.png) [@machong](https://discuss.elastic.co/u/machong)\
**Post date:** [May 17, 2018, 1:01pm UTC](https://discuss.elastic.co/t/mapper-turns-out-to-be-very-slow/131877/6 "2018-05-17T13:01:30Z")

</div>

James,  
i have a new discovery, the number of splits may have an impact on the performance of mapper.  
When i make es.input.max.docs.per.partition times of what it was to decrease the number of splits,  
my application had obvious increase in speed. However, the time it took is still too long for me, is there  
any other way to make it faster?

---

<div class="post-metadata">

**Author:** ![james.baiera](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/james.baiera/32/10209_2.png) [@james.baiera](https://discuss.elastic.co/u/james.baiera)\
**Post date:** [May 24, 2018, 3:52pm UTC](https://discuss.elastic.co/t/mapper-turns-out-to-be-very-slow/131877/7 "2018-05-24T15:52:36Z")

</div>

We've seen in some cases the slice feature can cause some slow downs. If you set `es.input.max.docs.per.partition` to a really high number, like max int, how does it do? Which version of the connector and ES are you running?

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [June 21, 2018, 3:52pm UTC](https://discuss.elastic.co/t/mapper-turns-out-to-be-very-slow/131877/8 "2018-06-21T15:52:40Z")

</div>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.
