SearchContextMissingException when doing scan search [0.90.7-0.90.13]


(Matteo Moci) #1

Hi All,
First of all, thanks for the nice work!

I found out that during a simple scan search (10 docs of 1 type, on 1 node,
1 index with 2 shards, no replicas, both v0.90.7 and v0.90.13),
I always receive this exception in the node logs (and it happens once per
type when I have more):

[2014-04-28 10:22:07,937][DEBUG][action.search.type ] [moxbook] [45]
Failed to execute query phase
org.elasticsearch.search.SearchContextMissingException: No search context
found for id [45]
at
org.elasticsearch.search.SearchService.findContext(SearchService.java:460)
at
org.elasticsearch.search.SearchService.executeScan(SearchService.java:211)
at
org.elasticsearch.search.action.SearchServiceTransportAction.sendExecuteScan(SearchServiceTransportAction.java:474)
at
org.elasticsearch.action.search.type.TransportSearchScrollScanAction$AsyncAction.executePhase(TransportSearchScrollScanAction.java:210)
at
org.elasticsearch.action.search.type.TransportSearchScrollScanAction$AsyncAction$2.run(TransportSearchScrollScanAction.java:180)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:722)

What worries me is that apparently in my tests, it is able to scan all the
docs with no missing records,
so I don't know if it's "normal" to have logs like this or if in some cases
it will lead to problems.

I already saw that there's a closed issue at [5165], but I don't know if
the fix
was already included in the releases I tried, 0.90.7 (surely not) and
0.90.13 (?).

Changing SearchOperationThreading doesn't help.

You can see the relevant snippet I used to get the exception at [1],
maybe there is something missing there?

Could someone help to find out if it's ok, or where the fix was introduced?
PS: I didn't upgrade to 1.x yet.

Best,
Matteo

[5165] https://github.com/elasticsearch/elasticsearch/issues/5165
[1] https://gist.github.com/mox601/545c7176785ef209f7f3

--
Matteo Moci
http://mox.fm

--
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.
To view this discussion on the web visit https://groups.google.com/d/msgid/elasticsearch/CAONgFZ5_Mx-3be461Pu2Sgn4jp0N4f_gbjKAGh2nwUf9vRj5pw%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.


(Jörg Prante) #2

The message is serious because it signals that your scan/scroll search has
prematurely ended and responses may be dropped (or not).

It would be nice to show us your code and your shard settings.

search.keep_alive_interval is the parameter that can influence the search
reaper, not search operation threading. The reaper runs each minute and
might run too frequently. While not sure about your setting of scan/scroll
lifetime, I can't tell more.

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.
To view this discussion on the web visit https://groups.google.com/d/msgid/elasticsearch/CAKdsXoHfGVg3xAeFXASg9%3DuiWr8w0pH24b6ucDvAfQeY_JC%3DPQ%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.


(Matteo Moci) #3

Hi Jorg,
Thanks for the reply.
If that helps, I linked a snippet with the code at [1].
In addition, the test I did was on 1 index, 2 shards with 0 replicas,
see the status at [2] and settings at [3].

Ho can I provide you more details?

Thanks,
Matteo

[1] https://gist.github.com/mox601/545c7176785ef209f7f3
[2] https://gist.github.com/mox601/fd806317dbe1d89ff12c
[3] https://gist.github.com/mox601/11366726

On Mon, Apr 28, 2014 at 10:56 AM, joergprante@gmail.com <
joergprante@gmail.com> wrote:

The message is serious because it signals that your scan/scroll search has
prematurely ended and responses may be dropped (or not).

It would be nice to show us your code and your shard settings.

search.keep_alive_interval is the parameter that can influence the search
reaper, not search operation threading. The reaper runs each minute and
might run too frequently. While not sure about your setting of scan/scroll
lifetime, I can't tell more.

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.
To view this discussion on the web visit
https://groups.google.com/d/msgid/elasticsearch/CAKdsXoHfGVg3xAeFXASg9%3DuiWr8w0pH24b6ucDvAfQeY_JC%3DPQ%40mail.gmail.comhttps://groups.google.com/d/msgid/elasticsearch/CAKdsXoHfGVg3xAeFXASg9%3DuiWr8w0pH24b6ucDvAfQeY_JC%3DPQ%40mail.gmail.com?utm_medium=email&utm_source=footer
.
For more options, visit https://groups.google.com/d/optout.

--
Matteo Moci
http://mox.fm

--
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.
To view this discussion on the web visit https://groups.google.com/d/msgid/elasticsearch/CAONgFZ7cMtUW%3Dyco3EMSA_2p9NPFN3KRAWuiaCA6MGHWv5R0kA%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.


(Jörg Prante) #4

Thanks - it helps!

Not sure about the "new Scroll(keepAlive)"

In my code, I use .setScroll(TimeValue.timeValueSeconds(30))

Maybe this helps?

Jörg

On Mon, Apr 28, 2014 at 11:32 AM, Matteo Moci mox601@gmail.com wrote:

Hi Jorg,
Thanks for the reply.
If that helps, I linked a snippet with the code at [1].
In addition, the test I did was on 1 index, 2 shards with 0 replicas,
see the status at [2] and settings at [3].

Ho can I provide you more details?

Thanks,
Matteo

[1] https://gist.github.com/mox601/545c7176785ef209f7f3
[2] https://gist.github.com/mox601/fd806317dbe1d89ff12c
[3] https://gist.github.com/mox601/11366726

On Mon, Apr 28, 2014 at 10:56 AM, joergprante@gmail.com <
joergprante@gmail.com> wrote:

The message is serious because it signals that your scan/scroll search
has prematurely ended and responses may be dropped (or not).

It would be nice to show us your code and your shard settings.

search.keep_alive_interval is the parameter that can influence the search
reaper, not search operation threading. The reaper runs each minute and
might run too frequently. While not sure about your setting of scan/scroll
lifetime, I can't tell more.

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.
To view this discussion on the web visit
https://groups.google.com/d/msgid/elasticsearch/CAKdsXoHfGVg3xAeFXASg9%3DuiWr8w0pH24b6ucDvAfQeY_JC%3DPQ%40mail.gmail.comhttps://groups.google.com/d/msgid/elasticsearch/CAKdsXoHfGVg3xAeFXASg9%3DuiWr8w0pH24b6ucDvAfQeY_JC%3DPQ%40mail.gmail.com?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.

--
Matteo Moci
http://mox.fm

--
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.
To view this discussion on the web visit
https://groups.google.com/d/msgid/elasticsearch/CAONgFZ7cMtUW%3Dyco3EMSA_2p9NPFN3KRAWuiaCA6MGHWv5R0kA%40mail.gmail.comhttps://groups.google.com/d/msgid/elasticsearch/CAONgFZ7cMtUW%3Dyco3EMSA_2p9NPFN3KRAWuiaCA6MGHWv5R0kA%40mail.gmail.com?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.

--
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.
To view this discussion on the web visit https://groups.google.com/d/msgid/elasticsearch/CAKdsXoGaUzBC18f1J%3D2uyjMkpUtGsMf8WcWeZLzoHr6yHA5evQ%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.


(Jörg Prante) #5

OK, the "new Scroll(...)" should'nt make any difference....

Maybe the cause for theerror message is the clear scroll call at the end?
If so, it shouldn't be serious.

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.
To view this discussion on the web visit https://groups.google.com/d/msgid/elasticsearch/CAKdsXoGUec-BG2%2BJz9VOjXMjjwEeqxqMyA2XNusWCmMBKt0f8w%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.


(Matteo Moci) #6

Hi Jorg,
Investigating on what call the exception relates to,
I ran the search on 2 types, and I'll show you the merged logs of my client
and the one printed on the node:

[2014-04-28 12:09:07,438][DEBUG][action.search.type ] [moxbook-pro]
[2] Failed to execute query phase
2014-04-28 12:09:07,442/CEST [main] INFO finished scrolling, hits length
<=0
[2014-04-28 12:09:07,455][DEBUG][action.search.type ] [moxbook-pro]
[3] Failed to execute query phase
2014-04-28 12:09:07,456/CEST [main] INFO finished scrolling, hits length
<=0

The client logs are printed by the client code (running on the same
machine),
once per type, after exiting the while (hits.length > 0) scroll's cycle and
before calling the clear scroll at the end.

So to wrap up, according to what I see, the error message
of the failing execute query phase happens before the clear scroll.

Following another path and reading your first email,
I added to the configuration file elasticsearch.yml the line:

search.keep_alive_interval: 1H
hoping to set the search keep alive explicitly on the node.

Starting the node like this:
$ ./elasticsearch -f -Des.logger.level=DEBUG
gives this log [1], but can't find mention of the keep alive interval I set
up.

Is it the right parameter name, and should it help?

Thanks,
Matteo

[1] https://gist.github.com/mox601/11368114

On Mon, Apr 28, 2014 at 11:53 AM, joergprante@gmail.com <
joergprante@gmail.com> wrote:

OK, the "new Scroll(...)" should'nt make any difference....

Maybe the cause for theerror message is the clear scroll call at the end?
If so, it shouldn't be serious.

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.
To view this discussion on the web visit
https://groups.google.com/d/msgid/elasticsearch/CAKdsXoGUec-BG2%2BJz9VOjXMjjwEeqxqMyA2XNusWCmMBKt0f8w%40mail.gmail.comhttps://groups.google.com/d/msgid/elasticsearch/CAKdsXoGUec-BG2%2BJz9VOjXMjjwEeqxqMyA2XNusWCmMBKt0f8w%40mail.gmail.com?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.

--
Matteo Moci
http://mox.fm

--
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.
To view this discussion on the web visit https://groups.google.com/d/msgid/elasticsearch/CAONgFZ5gcpx2nXUZ31qHWrLb_LB8vpXPCJsmUH9-HAMF34HDmw%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.


(Jörg Prante) #7

Reviewing your code, you have made a small mistake.

In the while loop, do not use currentScanSearchResp.getScrollId()

This can get outdated in the while loop.

Instead, use searchResponse.getScrollId()

Background info: the scroll ID changes from response to response!

Jörg

On Mon, Apr 28, 2014 at 12:44 PM, Matteo Moci mox601@gmail.com wrote:

Hi Jorg,
Investigating on what call the exception relates to,
I ran the search on 2 types, and I'll show you the merged logs of my
client and the one printed on the node:

[2014-04-28 12:09:07,438][DEBUG][action.search.type ]
[moxbook-pro] [2] Failed to execute query phase
2014-04-28 12:09:07,442/CEST [main] INFO finished scrolling, hits
length <=0
[2014-04-28 12:09:07,455][DEBUG][action.search.type ]
[moxbook-pro] [3] Failed to execute query phase
2014-04-28 12:09:07,456/CEST [main] INFO finished scrolling, hits
length <=0

The client logs are printed by the client code (running on the same
machine),
once per type, after exiting the while (hits.length > 0) scroll's cycle
and
before calling the clear scroll at the end.

So to wrap up, according to what I see, the error message
of the failing execute query phase happens before the clear scroll.

Following another path and reading your first email,
I added to the configuration file elasticsearch.yml the line:

search.keep_alive_interval: 1H
hoping to set the search keep alive explicitly on the node.

Starting the node like this:
$ ./elasticsearch -f -Des.logger.level=DEBUG
gives this log [1], but can't find mention of the keep alive interval I
set up.

Is it the right parameter name, and should it help?

Thanks,
Matteo

[1] https://gist.github.com/mox601/11368114

On Mon, Apr 28, 2014 at 11:53 AM, joergprante@gmail.com <
joergprante@gmail.com> wrote:

OK, the "new Scroll(...)" should'nt make any difference....

Maybe the cause for theerror message is the clear scroll call at the end?
If so, it shouldn't be serious.

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.
To view this discussion on the web visit
https://groups.google.com/d/msgid/elasticsearch/CAKdsXoGUec-BG2%2BJz9VOjXMjjwEeqxqMyA2XNusWCmMBKt0f8w%40mail.gmail.comhttps://groups.google.com/d/msgid/elasticsearch/CAKdsXoGUec-BG2%2BJz9VOjXMjjwEeqxqMyA2XNusWCmMBKt0f8w%40mail.gmail.com?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.

--
Matteo Moci
http://mox.fm

--
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.
To view this discussion on the web visit
https://groups.google.com/d/msgid/elasticsearch/CAONgFZ5gcpx2nXUZ31qHWrLb_LB8vpXPCJsmUH9-HAMF34HDmw%40mail.gmail.comhttps://groups.google.com/d/msgid/elasticsearch/CAONgFZ5gcpx2nXUZ31qHWrLb_LB8vpXPCJsmUH9-HAMF34HDmw%40mail.gmail.com?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.

--
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.
To view this discussion on the web visit https://groups.google.com/d/msgid/elasticsearch/CAKdsXoH1pfcM3UgBmNe9Yq%2BS9S%3DOY7eo_P1urGs5Kj2wORv%2BWQ%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.


(Matteo Moci) #8

Well spotted Joerg!
I knew the scroll id was changing,
anyway in the end I coded it wrong.

Thanks and keep up the good work!
Matteo

On Mon, Apr 28, 2014 at 1:29 PM, joergprante@gmail.com <
joergprante@gmail.com> wrote:

Reviewing your code, you have made a small mistake.

In the while loop, do not use currentScanSearchResp.getScrollId()

https://gist.github.com/mox601/545c7176785ef209f7f3#file-scroll-search-java-L59

This can get outdated in the while loop.

Instead, use searchResponse.getScrollId()

Background info: the scroll ID changes from response to response!

Jörg

On Mon, Apr 28, 2014 at 12:44 PM, Matteo Moci mox601@gmail.com wrote:

Hi Jorg,
Investigating on what call the exception relates to,
I ran the search on 2 types, and I'll show you the merged logs of my
client and the one printed on the node:

[2014-04-28 12:09:07,438][DEBUG][action.search.type ]
[moxbook-pro] [2] Failed to execute query phase
2014-04-28 12:09:07,442/CEST [main] INFO finished scrolling, hits
length <=0
[2014-04-28 12:09:07,455][DEBUG][action.search.type ]
[moxbook-pro] [3] Failed to execute query phase
2014-04-28 12:09:07,456/CEST [main] INFO finished scrolling, hits
length <=0

The client logs are printed by the client code (running on the same
machine),
once per type, after exiting the while (hits.length > 0) scroll's cycle
and
before calling the clear scroll at the end.

So to wrap up, according to what I see, the error message
of the failing execute query phase happens before the clear scroll.

Following another path and reading your first email,
I added to the configuration file elasticsearch.yml the line:

search.keep_alive_interval: 1H
hoping to set the search keep alive explicitly on the node.

Starting the node like this:
$ ./elasticsearch -f -Des.logger.level=DEBUG
gives this log [1], but can't find mention of the keep alive interval I
set up.

Is it the right parameter name, and should it help?

Thanks,
Matteo

[1] https://gist.github.com/mox601/11368114

On Mon, Apr 28, 2014 at 11:53 AM, joergprante@gmail.com <
joergprante@gmail.com> wrote:

OK, the "new Scroll(...)" should'nt make any difference....

Maybe the cause for theerror message is the clear scroll call at the
end? If so, it shouldn't be serious.

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.
To view this discussion on the web visit
https://groups.google.com/d/msgid/elasticsearch/CAKdsXoGUec-BG2%2BJz9VOjXMjjwEeqxqMyA2XNusWCmMBKt0f8w%40mail.gmail.comhttps://groups.google.com/d/msgid/elasticsearch/CAKdsXoGUec-BG2%2BJz9VOjXMjjwEeqxqMyA2XNusWCmMBKt0f8w%40mail.gmail.com?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.

--
Matteo Moci
http://mox.fm

--
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.
To view this discussion on the web visit
https://groups.google.com/d/msgid/elasticsearch/CAONgFZ5gcpx2nXUZ31qHWrLb_LB8vpXPCJsmUH9-HAMF34HDmw%40mail.gmail.comhttps://groups.google.com/d/msgid/elasticsearch/CAONgFZ5gcpx2nXUZ31qHWrLb_LB8vpXPCJsmUH9-HAMF34HDmw%40mail.gmail.com?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.

--
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.
To view this discussion on the web visit
https://groups.google.com/d/msgid/elasticsearch/CAKdsXoH1pfcM3UgBmNe9Yq%2BS9S%3DOY7eo_P1urGs5Kj2wORv%2BWQ%40mail.gmail.comhttps://groups.google.com/d/msgid/elasticsearch/CAKdsXoH1pfcM3UgBmNe9Yq%2BS9S%3DOY7eo_P1urGs5Kj2wORv%2BWQ%40mail.gmail.com?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.

--
Matteo Moci
http://mox.fm

--
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.
To view this discussion on the web visit https://groups.google.com/d/msgid/elasticsearch/CAONgFZ6XDw4c_2Lpax%3DBcM%2BTvtNCP4yfssbOTHs8R7_p1wiXmQ%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.


(system) #9