Faceting using DFS_QUERY_THEN_FETCH fails

[spinscale]

Hey,

this came via the ML (there are also some prerequisites listed): https://groups.google.com/d/msg/elasticsearch/ySHfbIW4sBQ/8ozOkBcbWTMJ

Works on master, fails on 0.90

To reproduce (sometimes, not always)

public class BrokenFacetTest extends ElasticsearchIntegrationTest {

    @Test
    @TestLogging("_root:DEBUG")
    public void foo() throws Exception {
        client().prepareIndex("test-index", "test-type")
                .setSource("{ \"id\": 123, \"test-value\": 321 }")
                .setRefresh(true)
                .execute()
                .actionGet();

        SearchResponse searchResponse = client()
                .prepareSearch("test-index")
                .setQuery(new MatchAllQueryBuilder())
                .addFacet(new TermsFacetBuilder("test-facet").field("test-value"))
                .setSearchType(SearchType.DFS_QUERY_AND_FETCH)
                .execute()
                .actionGet();

        assertEquals(searchResponse.getFailedShards(), 0); // Failing!
    }

}

Exception being logged

[2014-01-16 10:13:16,061][DEBUG][org.elasticsearch.action.search.type] [node_2] [2] Failed to execute query phase
org.elasticsearch.ElasticSearchException
    at org.elasticsearch.ExceptionsHelper.convertToRuntime(ExceptionsHelper.java:37)
    at org.elasticsearch.search.SearchService.executeFetchPhase(SearchService.java:360)
    at org.elasticsearch.search.action.SearchServiceTransportAction.sendExecuteFetch(SearchServiceTransportAction.java:338)
    at org.elasticsearch.action.search.type.TransportSearchDfsQueryAndFetchAction$AsyncAction.executeSecondPhase(TransportSearchDfsQueryAndFetchAction.java:139)
    at org.elasticsearch.action.search.type.TransportSearchDfsQueryAndFetchAction$AsyncAction$2.run(TransportSearchDfsQueryAndFetchAction.java:123)
    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)
Caused by: java.lang.AssertionError
    at org.elasticsearch.common.recycler.ThreadLocalRecycler$TV.release(ThreadLocalRecycler.java:84)
    at org.elasticsearch.search.facet.terms.longs.TermsLongFacetExecutor.buildFacet(TermsLongFacetExecutor.java:122)
    at org.elasticsearch.search.facet.FacetPhase.execute(FacetPhase.java:200)
    at org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:129)
    at org.elasticsearch.search.SearchService.executeFetchPhase(SearchService.java:357)
    ... 6 more

[jpountz]

There is indeed an issue in the case of DFS_QUERY_AND_FETCH because the facet executor is initialized and requests a recycled object in executeDfsPhase while facets are built (and recycled objects released) in executeFetchPhase. For reference, here are a stack trace of allocation and release:

at org.elasticsearch.common.recycler.ThreadLocalRecycler$TV.<init>(ThreadLocalRecycler.java:67)
    at org.elasticsearch.common.recycler.ThreadLocalRecycler.obtain(ThreadLocalRecycler.java:57)
    at org.elasticsearch.common.recycler.Recycler$Sizing.obtain(Recycler.java:47)
    at org.elasticsearch.cache.recycler.CacheRecycler.longIntMap(CacheRecycler.java:236)
    at org.elasticsearch.search.facet.terms.longs.TermsLongFacetExecutor.<init>(TermsLongFacetExecutor.java:71)
    at org.elasticsearch.search.facet.terms.TermsFacetParser.parse(TermsFacetParser.java:214)
    at org.elasticsearch.search.facet.FacetParseElement.parse(FacetParseElement.java:94)
    at org.elasticsearch.search.SearchService.parseSource(SearchService.java:569)
    at org.elasticsearch.search.SearchService.createContext(SearchService.java:484)
    at org.elasticsearch.search.SearchService.createContext(SearchService.java:469)
    at org.elasticsearch.search.SearchService.createAndPutContext(SearchService.java:462)
    at org.elasticsearch.search.SearchService.executeDfsPhase(SearchService.java:168)
    at org.elasticsearch.search.action.SearchServiceTransportAction.sendExecuteDfs(SearchServiceTransportAction.java:168)
at org.elasticsearch.action.search.type.TransportSearchDfsQueryAndFetchAction$AsyncAction.sendExecuteFirstPhase(TransportSearchDfsQueryAndFetchAction.java:77)
    at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:216)
    at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction.performFirstPhase(TransportSearchTypeAction.java:203)
    at org.elasticsearch.action.search.type.TransportSearchTypeAction$BaseAsyncAction$2.run(TransportSearchTypeAction.java:186)
    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)

at org.elasticsearch.common.recycler.ThreadLocalRecycler$TV.release(ThreadLocalRecycler.java:88)
    at org.elasticsearch.search.facet.terms.longs.TermsLongFacetExecutor.buildFacet(TermsLongFacetExecutor.java:104)
    at org.elasticsearch.search.facet.FacetPhase.execute(FacetPhase.java:200)
    at org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:129)
    at org.elasticsearch.search.SearchService.executeFetchPhase(SearchService.java:357)

[jpountz]

Even though this assertion failure shows that the recycler is not used optimally (the reference is acquired and used in different phases), I think this doesn't break anything. Since facets are going to be progressively replaced by aggregations, I'm wondering if we should just remove the assertion instead of trying to fix the issue?

[s1monw]

so I don't want to loose the ability to fail if it's not released in the same thread to be honest. can we somehow only special case the broken facet impls?

[s1monw]

@jpountz can we actually close this?

[jpountz]

Closed via f7e887b

[jpountz]

For reference, the root cause of this issue has been fixed in #5821