Documents missing after indexing and refreshing

Wojciech_Durczynski · August 26, 2011, 3:18pm

Hello Shay.

I noticed a problem with ES 0.17.
I have automatic tests that:

creates two local ES nodes with different cluster names
create index without mappings in one of the nodes
add there a lot of documents quickly (without refresh) - mapping is
generated automatically
refresh this index
create another index in the second node
read all documents from first index (scan) and index them in second index
(other cluster) - mappings are created automatically
close first node
refresh second index
search a document from second index

This scenario is used by many of my tests, and it sometimes fail in
non-deterministic way (document is not found). After a while this document
is searchable.

In ES 0.16 after indexing and refreshing search was always successful. In ES
0.17 it isn't.
Do You know what may be a source of this problem? Maybe reading from replica
is introduced in 0.17 or different caching than before?

Regards
Wojciech Durczyński

kimchy · August 26, 2011, 3:50pm

Hey,

Is there a chance you can extract it into a standalone test that I can run
and gist it? If this happens, I think you should be able to simplify it by
just indexing data into a node, the indexing process does not care where the
documents came from.

-shay.banon

2011/8/26 Wojciech Durczyński wojciech.durczynski@comarch.com

Hello Shay.

I noticed a problem with ES 0.17.
I have automatic tests that:

creates two local ES nodes with different cluster names

create index without mappings in one of the nodes

add there a lot of documents quickly (without refresh) - mapping is
generated automatically

refresh this index

create another index in the second node

read all documents from first index (scan) and index them in second
index (other cluster) - mappings are created automatically

close first node

refresh second index

search a document from second index

This scenario is used by many of my tests, and it sometimes fail in
non-deterministic way (document is not found). After a while this document
is searchable.

In ES 0.16 after indexing and refreshing search was always successful. In
ES 0.17 it isn't.
Do You know what may be a source of this problem? Maybe reading from
replica is introduced in 0.17 or different caching than before?

Regards
Wojciech Durczyński

Wojciech_Durczynski · August 29, 2011, 12:27pm

Here is my test example (in Scala but using Elastic Search Java API):

gist.github.com

https://gist.github.com/Avatah/1178293

gistfile1.txt

    val indexName = "testindex"
    val typeName = "testType"

    var loop: Int = 1

    while (true) {
      val node = NodeBuilder.nodeBuilder().local(true).loadConfigSettings(false).clusterName("testCluster").settings(
        ImmutableSettings.settingsBuilder
          .put("gateway.type", "none")
          //              .put("index.store.type", "memory")

This file has been truncated. show original

Version 0.17.5 of ES fails assertion before 100th loop.
Version 0.16.2 of ES doesn't fail assertion.

Wojciech_Durczynski · August 29, 2011, 12:54pm

In ES 0.16.2 sometimes there is an exception:
org.elasticsearch.indices.IndexAlreadyExistsException: [testindex] Already
exists
at
org.elasticsearch.cluster.metadata.MetaDataCreateIndexService.validate(MetaDataCreateIndexService.java:401)
at
org.elasticsearch.cluster.metadata.MetaDataCreateIndexService.access$100(MetaDataCreateIndexService.java:79)
at
org.elasticsearch.cluster.metadata.MetaDataCreateIndexService$1.execute(MetaDataCreateIndexService.java:126)
at
org.elasticsearch.cluster.service.InternalClusterService$2.run(InternalClusterService.java:180)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)

Wojciech_Durczynski · August 29, 2011, 1:17pm

I modified a little this test:

gist.github.com

https://gist.github.com/Avatah/1178368

gistfile1.txt

    var loop: Int = 1

    while (true) {
      val id = UUID.randomUUID().toString
      def indexName = "testindex" + loop
      def typeName = "testType" + loop
      val node = NodeBuilder.nodeBuilder().local(true).loadConfigSettings(false).clusterName("testCluster").settings(
        ImmutableSettings.settingsBuilder
          .put("gateway.type", "none")
          //              .put("index.store.type", "memory")

This file has been truncated. show original

If document can't be searched by name in ES 0.17.5 it is always gettable by
id.
I get message: Record wasn't found after 10s but can be get by id

Wojciech_Durczynski · August 31, 2011, 6:25pm

What do You think about this Shay? Is it a bug, or I'm doing something
wrong?

Wojciech_Durczynski · September 22, 2011, 11:56am

Hello Shay. I improved my test case. This time it's in Java:

gist.github.com

https://gist.github.com/1234552

gistfile1.java

    Node node = NodeBuilder.nodeBuilder().local(true).loadConfigSettings(false).clusterName("testCluster").settings(
      ImmutableSettings.settingsBuilder()
        .put("gateway.type", "none")
        .put("path.data", new File("target/data").getAbsolutePath())
        .build()).node();
    Client client = node.client();

    for (int loop = 1; loop < 1000; loop++) {
      String indexName = "testindex" + loop;
      String typeName = "testType" + loop;

This file has been truncated. show original

Problem is that in ES 0.17.* (I checked versions 0.17.5 and 0.17.7) this
code throws an exception "Record wasn't found after 10s but can be get by
id".
But this code works well in ES 0.16.2.
It's because in ES 0.16.2 putMapping returns when mapping is successfully
created and in ES 0.17.* it returns earlier.
If mapping isn't created before indexing, then indexing is wrong and object
can't be found by search operation.
If "sleep after put mapping" is uncommented, then this test case works
better in ES 0.17.*.
But then there are sometimes errors: Record found after 100 ms. It means
that mapping was succesfully created before indexing of object, but object
isn't searchable yet even after refresh. Uncommenting "sleep after refresh"
solves this problem. Maybe it's because refresh returns before refreshing
operation finishes?

I'm sure that it's a regression and execute().actionGet() should return
after operation is succesfully finished. What do you think about it?
*
*
*
*
*
*

kimchy · September 22, 2011, 1:01pm

Hi,

Thanks for the recreation, opened an issue:
Put mapping on a single node with new mapping will not wait for the mapping to be applied · Issue #1355 · elastic/elasticsearch · GitHub. The problem is
that put mapping on a single node will not wait for the mapping to be
applied so a subsequent index request might sneak in.

Btw, if you want to fully protect against that, even in the distributed /
multi client scenario, you can simply have the mappings set as part of hte
create index API.

-shay.banon

2011/9/22 Wojciech Durczyński wojciech.durczynski@comarch.com

Hello Shay. I improved my test case. This time it's in Java:
1234552’s gists · GitHub

Problem is that in ES 0.17.* (I checked versions 0.17.5 and 0.17.7) this
code throws an exception "Record wasn't found after 10s but can be get by
id".
But this code works well in ES 0.16.2.
It's because in ES 0.16.2 putMapping returns when mapping is successfully
created and in ES 0.17.* it returns earlier.
If mapping isn't created before indexing, then indexing is wrong and object
can't be found by search operation.
If "sleep after put mapping" is uncommented, then this test case works
better in ES 0.17.*.
But then there are sometimes errors: Record found after 100 ms. It means
that mapping was succesfully created before indexing of object, but object
isn't searchable yet even after refresh. Uncommenting "sleep after refresh"
solves this problem. Maybe it's because refresh returns before refreshing
operation finishes?

I'm sure that it's a regression and execute().actionGet() should return
after operation is succesfully finished. What do you think about it?
*
*
*
*
*
*

Wojciech_Durczynski · September 22, 2011, 1:14pm

Thank you for your answer.
I modified this test case to create two nodes cluster.
And now: "Record wasn't found after 10s but can be get by id" error happens
much less but still exists.
"Record found after 100 m" error happens very often - refresh operation
doesn't work well even in two nodes cluster.

kimchy · September 22, 2011, 1:22pm

Can you try with the change I just committed, see if it fixes it? I ran your
test and have not encountered it. Its committed on both 0.17 branch and
master.

2011/9/22 Wojciech Durczyński wojciech.durczynski@comarch.com

Thank you for your answer.
I modified this test case to create two nodes cluster.
And now: "Record wasn't found after 10s but can be get by id" error happens
much less but still exists.
"Record found after 100 m" error happens very often - refresh operation
doesn't work well even in two nodes cluster.

Wojciech_Durczynski · September 22, 2011, 3:32pm

I tried current master with your change.
PutMapping works as a charm - mapping is now always available when document
is indexed.
But there is still problem with refresh.
After indexing and refreshing sometimes object isn't found (but becomes
searchable after a while).
My test case fails now with "Record found after 100 ms" error always after
5-200 loops.

Wojciech_Durczynski · September 23, 2011, 1:29pm

I did some more tests using master revision and:

scenario 1:
create index
putMapping
sleep
loop {
index
refresh
search
}
works without problems. If index is created much before loop, then
refreshing works and document is always searchable after refresh.

scenario2:
loop {
create index
putMapping
index
refresh
search
}
fails very quickly, usually at 2nd loop. Mapping is created well but indexed
document isn't searchable after refresh if index was created recently. It
becomes searchable after a while.

scenario3:
loop {
create index
putMapping
wait for yellow status
index
refresh
search
}
doesn't fail as quickly as scenario2, but also fails. It means that even
waiting for yellow status doesn't assure as that document will be searchable
after indexing and refreshing. It becomes searchable after a while.

I'd like to be sure that I'll find all documents which was indexed before
search. How to do this?

Frederic · September 26, 2011, 12:50pm

Hi there. For what it worths, same issue here but with default index
and mapping creation at indexing time. Searching items right after
indexing them and refreshing the index, does found documents but not
all of them. Sleeping 5secs after populating ES does the work. (main
parts of the test at Populating and immediately searching ES Test · GitHub)

On 23 sep, 10:29, Wojciech Durczyński
wojciech.durczyn...@comarch.com wrote:

I did some more tests using master revision and:

scenario 1:
create index
putMapping
sleep
loop {
index
refresh
search}

works without problems. If index is created much before loop, then
refreshing works and document is always searchable after refresh.

scenario2:
loop {
create index
putMapping
index
refresh
search}

fails very quickly, usually at 2nd loop. Mapping is created well but indexed
document isn't searchable after refresh if index was created recently. It
becomes searchable after a while.

scenario3:
loop {
create index
putMapping
wait for yellow status
index
refresh
search}

doesn't fail as quickly as scenario2, but also fails. It means that even
waiting for yellow status doesn't assure as that document will be searchable
after indexing and refreshing. It becomes searchable after a while.

I'd like to be sure that I'll find all documents which was indexed before
search. How to do this?

kimchy · September 27, 2011, 8:59pm

Hey,

Ran the test again, but now with deleting the index so I can run it over
night, and it managed to fail (~3000 iteration). I guess the difference
comes from the different HW we use as its a concurrency problem. I pushed
two fixes to master that fix the ones that I managed to recreate (
Fetch phase when searching might fail when mapping are updated with type missing · Issue #1369 · elastic/elasticsearch · GitHub, and
When refreshing, also execute the refresh operation on initializing shards to make sure we don't miss it · Issue #1370 · elastic/elasticsearch · GitHub). They mainly
relate to replica shard recovery and applying refresh / mapping to it. Can
you give it a go?

-shay.banon

2011/9/23 Wojciech Durczyński wojciech.durczynski@comarch.com

I did some more tests using master revision and:

scenario 1:
create index
putMapping
sleep
loop {
index
refresh
search
}
works without problems. If index is created much before loop, then
refreshing works and document is always searchable after refresh.

scenario2:
loop {
create index
putMapping
index
refresh
search
}
fails very quickly, usually at 2nd loop. Mapping is created well but
indexed document isn't searchable after refresh if index was created
recently. It becomes searchable after a while.

scenario3:
loop {
create index
putMapping
wait for yellow status
index
refresh
search
}
doesn't fail as quickly as scenario2, but also fails. It means that even
waiting for yellow status doesn't assure as that document will be searchable
after indexing and refreshing. It becomes searchable after a while.

I'd like to be sure that I'll find all documents which was indexed before
search. How to do this?

Wojciech_Durczynski · September 28, 2011, 9:28am

I tried current master and my tests passed. Your patch seems to be working.
Is it possible to include changes from this thread (issue 1355, 1369 and
1370) in ES 0.17.8?
When do you plan to release it, and when 0.18.0?

Regards
Wojciech Durczyński

kimchy · September 28, 2011, 10:06am

The fixes are in 0.17 branch. No concrete date for 0.18, 0.17.8 can probably
be released in a week or so.

2011/9/28 Wojciech Durczyński wojciech.durczynski@comarch.com

I tried current master and my tests passed. Your patch seems to be working.
Is it possible to include changes from this thread (issue 1355, 1369 and
1370) in ES 0.17.8?
When do you plan to release it, and when 0.18.0?

Regards
Wojciech Durczyński