Get requests get slower as the index grow

Hi,
I'm running an index loader which indexes 1000 doc each bulk.
before indexing, the loader runs a get request for each doc id in order to see if exist. If it exist,
I'm doing a merge(my own) for the document and re indexing it.
I noticed that until the index gets to 1M docs, the process runs really fast. It get to 1M in less then 10 minutes.
After reaching the 1M threshold, I can tell that the get requests(for the check) are getting slower and slower. from 1 millisecond for a single get request at the beginning, it gets up to 155 millisecond. When multiplying by 1000 it means that I'm indexing a bulk of 1000 docs every 155s instead of 1s.

When restarting the loader I get the same speed so this doesn't appear to be on the loader side.
Also, when looking via bigDesk monitor, I can see that the node is receiving less request per second when it reaches the 1M gap(or handles less per second. I can't tell).

Any ideas how why I'm having this behavior? I think ES has a better stable get response time, especially at these volumes.

I should mention that the bulk index request stays pretty fast and stable.

some more details: 2 EC(hs1.8xlarge)2 node cluster with default 5 shards 1 replica configuration. 2 indexes set, but loading to one at a time.

Thanks in advanced,

Oren

From the latency you stated, I deduce you found the spot where your ES node
must execute disk accesses for getting docs because memory is exhausted.
Without knowing the details how the action looks like for getting the
document and how you configured ES, it is hard to say anything more.

A general performance relevant design issue is mixing bulk writes with gets
(or queries). There are advanced methods to reduce the stress, e.g. to
execute multiget or terms query rarely, or even totally separate from bulk
writes, at different times. So, ES index building is not disturbed by reads.

Note, the bulk action in 0.90.2+ also supports updating. You save a
roundtrip compared to your handmade method, if you can sort out the
document order properly in order to get them correctly updated per bulk
actions. But the workload will still be a mixed one.

Jörg

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

Hi Jörg,
thanks a lot for the input. It looks like my memory is far from it's max usage(set to 20G).
The only thing that I see that gets to its limit is the non heap memory that reaches40mb. can that be the case? any idea how can I increase the non heap memory?

please see attached<nabble_img src="bigdesk.png" border="0"/>

Thanks,

Non-heap memory is mostly loaded classes so it won't increase much after
your application has been running for a while. It isn't the problem. I
don't believe memory to be your problem because you aren't seeing any GCs.

What kind of disk IO are you seeing when things are working well vs working
poorly?

Also, does elasticsearch spit out any different kinds of logs in the bad
times vs the good times?

On Thu, Aug 8, 2013 at 10:28 AM, oreno oreno@exelate.com wrote:

Hi Jörg,
thanks a lot for the input. It looks like my memory is far from it's max
usage(set to 20G).
The only thing that I see that gets to its limit is the non heap memory
that
reaches40mb. can that be the case? any idea how can I increase the non
heap memory?

please see attached
<http://elasticsearch-users.115913.n3.nabble.com/file/n4039334/bigdesk.png

Thanks,

--
View this message in context:
http://elasticsearch-users.115913.n3.nabble.com/Get-requests-get-slower-as-the-index-grow-tp4039281p4039334.html
Sent from the ElasticSearch Users mailing list archive at Nabble.com.

--
You received this message because you are subscribed to the Google Groups
"elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an
email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

Can you see in your bigdesk image the mixed workload? Refresh is working
all the time, which gives poor performance.

Jörg

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

Hi,
I've already tried the refresh interval change but this doesn't seem to
have an effect on the get response time, maybe this is more useful when
having index time issues.
I've recreated the index to show you guys the sudden drop that I get for
the get requests. It shows as if it gets less requests, but actually I
conclude that it's the number of get requests that ES is able to handle.

Can you think of any reason for this behavior? it's like I'm getting to
some configured threshold ...

Thanks,

[image: Inline image 1]

On Thu, Aug 8, 2013 at 6:48 PM, joergprante@gmail.com [via ElasticSearch
Users] ml-node+s115913n4039341h6@n3.nabble.com wrote:

Can you see in your bigdesk image the mixed workload? Refresh is working
all the time, which gives poor performance.

Jörg

--
You received this message because you are subscribed to the Google Groups
"elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an
email to [hidden email]http://user/SendEmail.jtp?type=node&node=4039341&i=0
.
For more options, visit https://groups.google.com/groups/opt_out.


If you reply to this email, your message will be added to the discussion
below:

http://elasticsearch-users.115913.n3.nabble.com/Get-requests-get-slower-as-the-index-grow-tp4039281p4039341.html
To unsubscribe from Get requests get slower as the index grow, click herehttp://elasticsearch-users.115913.n3.nabble.com/template/NamlServlet.jtp?macro=unsubscribe_by_code&node=4039281&code=b3Jlbm9AZXhlbGF0ZS5jb218NDAzOTI4MXw4ODk1Mjk2Nzg=
.
NAMLhttp://elasticsearch-users.115913.n3.nabble.com/template/NamlServlet.jtp?macro=macro_viewer&id=instant_html!nabble%3Aemail.naml&base=nabble.naml.namespaces.BasicNamespace-nabble.view.web.template.NabbleNamespace-nabble.view.web.template.NodeNamespace&breadcrumbs=notify_subscribers!nabble%3Aemail.naml-instant_emails!nabble%3Aemail.naml-send_instant_email!nabble%3Aemail.naml

signature.bmp (1M) http://elasticsearch-users.115913.n3.nabble.com/attachment/4039354/0/signature.bmp
image.png (160K) http://elasticsearch-users.115913.n3.nabble.com/attachment/4039354/1/image.png

Sorry, but without having more information it is impossible to give useful
advise.

For example

  • what API do you use? Java/ HTTP?
  • what is the settings/mapping of the indexes you work with?
  • what parameters for the get action do you use?
  • what does an average doc look like?
  • how large are the bulk requests? what is the concurrency?
  • is the index for the get request different from the bulk index?
  • what is the config of your ES (indexes, shards, JVM, heap size, merge
    settings)?

Jörg

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

Hi Jörg, I really appreciate your help.

please see below:

On Fri, Aug 9, 2013 at 12:53 AM, joergprante@gmail.com [via ElasticSearch
Users] ml-node+s115913n4039361h26@n3.nabble.com wrote:

Sorry, but without having more information it is impossible to give useful
advise.

For example

  • what API do you use? Java/ HTTP? java api
  • what is the settings/mapping of the indexes you work with?

'{ "user": { "properties": { "name": { "type": "string" }, "events": {
"type": "nested", "properties": { "event_time": { "type": "Date" },
"products": { "properties": { "product": { "type": "string", "index":
"not_analyzed" } } } } } } } }'

  • what parameters for the get action do you use? *no special parameters
  • client.prepareGet(targetIndex, LoaderDefs.USER_DOC,
    userId).execute.actionGet*
  • what does an average doc look like? see below
  • how large are the bulk requests? what is the concurrency? *there are 5
    thread that execute a bulk of 1000 index request as fast as they can. They
    are slowing because of the get requests response time (which are not bulked)
  • is the index for the get request different from the bulk index? no
  • what is the config of your ES (indexes, shards, JVM, heap size, merge
    settings)?2 indexes default configuration, 5 shards, 1 replica,jdk 1.7,
    elastic version 90.2, heap size 20G(but using much less), default merge
    setting

*will usually have have more events for several days
_index: users_info_loader
_type: user
_id: 55831354bd9c03f8a2f2036f33baa302
_score: 1
_source: {

  • events: [{*
  • event_time: 2013-06-05 products: [{*
  • product: 2345271*
  • }{*
  • product: 2003609*
  • }{*
  • product: 2345266*
  • }{*
  • product: 2345296*
  • }{*
  • product: 2345270*
  • }{*
  • product: 2345277*
  • }{*
  • product: 1626533*
  • }{*
  • product: 1899788*
  • }{*
  • product: 2345297*
  • }{*
  • product: 1626529*
  • }{*
  • product: 1769138*
  • }{*
  • product: 1769254*
  • }{*
  • product: 2345282*
  • }{*
  • product: 1768139*
  • }{*
  • product: 1772175*
  • }{*
  • product: 185984*
  • }{*
  • product: 20205*
  • }{*
  • product: 23705*
  • }{*
  • product: 901788*
  • }{*
  • product: 184685*
  • }{*
  • product: 657034*
  • }{*
  • product: 1704233*
  • }{*
  • product: 2345293*
  • }{*
  • product: 2345260*
  • }{*
  • product: 2345261*
  • }{*
  • product: 80874*
  • }{*
  • product: 2345287*
  • }{*
  • product: 2345295*
  • }]*
  • }]*

oren,

Jörg

--
You received this message because you are subscribed to the Google Groups
"elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an
email to [hidden email]http://user/SendEmail.jtp?type=node&node=4039361&i=0
.
For more options, visit https://groups.google.com/groups/opt_out.


If you reply to this email, your message will be added to the discussion
below:

http://elasticsearch-users.115913.n3.nabble.com/Get-requests-get-slower-as-the-index-grow-tp4039281p4039361.html
To unsubscribe from Get requests get slower as the index grow, click herehttp://elasticsearch-users.115913.n3.nabble.com/template/NamlServlet.jtp?macro=unsubscribe_by_code&node=4039281&code=b3Jlbm9AZXhlbGF0ZS5jb218NDAzOTI4MXw4ODk1Mjk2Nzg=
.
NAMLhttp://elasticsearch-users.115913.n3.nabble.com/template/NamlServlet.jtp?macro=macro_viewer&id=instant_html!nabble%3Aemail.naml&base=nabble.naml.namespaces.BasicNamespace-nabble.view.web.template.NabbleNamespace-nabble.view.web.template.NodeNamespace&breadcrumbs=notify_subscribers!nabble%3Aemail.naml-instant_emails!nabble%3Aemail.naml-send_instant_email!nabble%3Aemail.naml

Thank you. I will try to reproduce the situation on my private hardware
with random docs. I have a similar workload, bulk indexing mixed with
querying terms and scrolling over result sets, with many megabytes per
second in the bulk and a constant 800 qps on a single node.

I am not sure if your get request is getting slow or your bulk indexing.

A common issue is that bulk indexing runs into merging and get slow,
ignoring the time the bulk responses need to return.

"...as fast as they can..." - can you confirm that your bulk requests wait
for the bulk responses before they continue, so that a maximum concurrency
of open bulk requests is not exceeded?

Jörg

--
You received this message because you are subscribed to the Google Groups "elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an email to elasticsearch+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

Yes, I'm sure that the indexing is not the problem. I have the below log
prints for details.

I admit that both the merge & indexing increases during time, but I clearly
see that the ES is just getting fewer index request because of the time
spent waiting for get responses.

*batching time(in seconds) - the total time it took to handle 1000 records.

user get time(in mill) in average is 156
user get time(in mill) in average is 160
user get time(in mill) in average is 161
ElasticSearchLoadWorker 2: indexed 1000 records in 7.784 seconds (batching
time =164.419).
ElasticSearchLoadWorker 1: indexed 1000 records in 3.939 seconds (batching
time =165.19).
ElasticSearchLoadWorker 4: indexed 1000 records in 4.638 seconds (batching
time =165.008).
user get time(in mill) in average is 169
user get time(in mill) in average is 169
ElasticSearchLoadWorker 0: indexed 1000 records in 1.489 seconds (batching
time =170.855).
ElasticSearchLoadWorker 3: indexed 1000 records in 1.422 seconds (batching
time =170.631).
user merge time(in mill) in average is 16
user merge time(in mill) in average is 13
user merge time(in mill) in average is 14
user merge time(in mill) in average is 7
user merge time(in mill) in average is 8

[image: Inline image 1]

[image: Inline image 1]
*
*
Oren Orgad | Software Engineer | eXelate http://www.exelate.com/

p: +972- 72-2221329 | e: oreno@exelate.com

On Fri, Aug 9, 2013 at 7:54 PM, joergprante@gmail.com [via ElasticSearch
Users] ml-node+s115913n4039402h97@n3.nabble.com wrote:

Thank you. I will try to reproduce the situation on my private hardware
with random docs. I have a similar workload, bulk indexing mixed with
querying terms and scrolling over result sets, with many megabytes per
second in the bulk and a constant 800 qps on a single node.

I am not sure if your get request is getting slow or your bulk indexing.

A common issue is that bulk indexing runs into merging and get slow,
ignoring the time the bulk responses need to return.

"...as fast as they can..." - can you confirm that your bulk requests wait
for the bulk responses before they continue, so that a maximum concurrency
of open bulk requests is not exceeded?

Jörg

--
You received this message because you are subscribed to the Google Groups
"elasticsearch" group.
To unsubscribe from this group and stop receiving emails from it, send an
email to [hidden email]http://user/SendEmail.jtp?type=node&node=4039402&i=0
.
For more options, visit https://groups.google.com/groups/opt_out.


If you reply to this email, your message will be added to the discussion
below:

http://elasticsearch-users.115913.n3.nabble.com/Get-requests-get-slower-as-the-index-grow-tp4039281p4039402.html
To unsubscribe from Get requests get slower as the index grow, click herehttp://elasticsearch-users.115913.n3.nabble.com/template/NamlServlet.jtp?macro=unsubscribe_by_code&node=4039281&code=b3Jlbm9AZXhlbGF0ZS5jb218NDAzOTI4MXw4ODk1Mjk2Nzg=
.
NAMLhttp://elasticsearch-users.115913.n3.nabble.com/template/NamlServlet.jtp?macro=macro_viewer&id=instant_html!nabble%3Aemail.naml&base=nabble.naml.namespaces.BasicNamespace-nabble.view.web.template.NabbleNamespace-nabble.view.web.template.NodeNamespace&breadcrumbs=notify_subscribers!nabble%3Aemail.naml-instant_emails!nabble%3Aemail.naml-send_instant_email!nabble%3Aemail.naml

Hi, just found out what the problem was, I didn't consider the response json parsing time.
I was using scala's default parser, and it's really bad.

Sorry for the trouble, and thank you for your help.

Oren,