Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Delete Index failed - not acked #7798

Closed
nickminutello opened this issue Sep 19, 2014 · 19 comments
Closed

Delete Index failed - not acked #7798

nickminutello opened this issue Sep 19, 2014 · 19 comments
Assignees
@s1monw
Labels
feedback_needed >test Issues or PRs that are addressing/adding tests

Comments

@nickminutello
Copy link

I am getting this error intermittently in the teardown of our tests (using ElasticsearchIntegrationTest).

Elastic 1.3.2 on Java 1.7 u65 on linux.

I cannot see why we should be getting this.

java.lang.AssertionError: Delete Index failed - not acked
Expected: <true>
     but: was <false>
    at __randomizedtesting.SeedInfo.seed([AB0B449635AD3C03:63F22B491E5E9323]:0)
    at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
    at org.elasticsearch.test.hamcrest.ElasticsearchAssertions.assertAcked(ElasticsearchAssertions.java:111)
    at org.elasticsearch.test.hamcrest.ElasticsearchAssertions.assertAcked(ElasticsearchAssertions.java:107)
    at org.elasticsearch.test.TestCluster.wipeIndices(TestCluster.java:128)
    at org.elasticsearch.test.TestCluster.wipe(TestCluster.java:70)
    at org.elasticsearch.test.ElasticsearchIntegrationTest.afterInternal(ElasticsearchIntegrationTest.java:540)
    at org.elasticsearch.test.ElasticsearchIntegrationTest.after(ElasticsearchIntegrationTest.java:1547)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
    at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:885)
    at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
    at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
    at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
    at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
    at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
    at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
    at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
    at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
    at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
    at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
    at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
    at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
    at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
    at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
    at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
    at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
    at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
    at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
    at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
    at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
    at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
    at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
    at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
    at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
    at java.lang.Thread.run(Thread.java:745)
@s1monw
Copy link
Contributor

s1monw commented Sep 19, 2014

can you tell what your test is doing or maybe even share it?

@s1monw s1monw added the >test Issues or PRs that are addressing/adding tests label Sep 19, 2014
@s1monw s1monw self-assigned this Sep 19, 2014
@nickminutello
Copy link
Author

It happens for different tests - there doesn't seem to be a pattern.
The tests index some documents & then run searches or aggregations...some tests use scrolling api.

Our tests are configured thus:

@ElasticsearchIntegrationTest.ClusterScope(scope = TEST, numClientNodes = 0, numDataNodes = 1)

@nickminutello
Copy link
Author

What does it actually mean that "not acked" - does it think the operation time out?

@javanna
Copy link
Member

javanna commented Sep 23, 2014

Hi @nickminutello every time a cluster state update needs to happen (happens when you delete an index for instance), it needs to be processed on the master node first. Once the master is done with that, it sends the new cluster state to all the other nodes in the cluster, which ack that once they processed it. If the response that you get is not acked, that means that at least one of the nodes didn't ack within the ack timeout (timeout request parameter, defaults to 30 seconds). The operation itself didn't timeout, only the processing on some of the non master nodes did. When retrieving the cluster state via cluster state api you would still get the latest one since the call goes to the master by default, which always has the most up-to-date version of it, but some of the non master nodes might be lagging behind. You can use the local flag to retrieve the local cluster state taken from the node that you hit with your call. It woud be interesting to understand which node(s) is not acking the delete index and why. Anything else that is running concurrently while testing?

@nickminutello
Copy link
Author

No, the tests are running on a TeamCity build agent. As far as I am aware, thats all that is happening.
In particular, the failure is happening in a test teardown (in the index deletion).

Given our usage of the following annotation:

@ElasticsearchIntegrationTest.ClusterScope(scope = TEST, numClientNodes = 0, numDataNodes = 1)

There should only be one (master) node, right? So I dont understand where the timeout occurred.

@nickminutello
Copy link
Author

The intermittent failing tests are creating havoc with our CI ... and I am no nearer to understanding the cause :(

@clintongormley
Copy link

@nickminutello i'd suggest showing the code in your test, either here or in a gist.

@nickminutello
Copy link
Author

I will try paste the contents of a test - its nothing too exciting - and the failures are very much at random (you never know which test might fail in cleanup)

@clintongormley
Copy link

Hi @nickminutello

Any more info on this?

@s1monw
Copy link
Contributor

s1monw commented Oct 31, 2014

@nickminutello can you share this testcase that hits this? is it reproducible?

@mikemccand
Copy link
Contributor

@nickminutello I think you may be hitting #8405

@nickminutello
Copy link
Author

It could be - but given our tests only index a small amount of data, I cant see it taking longer than 30s to delete.
HOWEVER, we could be timing out because our build-agent is heavily overloaded (its running on a linux vm - which is on a host that is heavily over-subscribed). We have never been able to reproduce it locally (maybe because we arent re-creating the same overloaded OS behaviour)

So we probably are seeing some kind of "timeout" - but its not clear from the error message that there was a timeout.

In any case, where is this timeout value set? I couldnt see anything from the elastic test support code that indicated any kind of timeout being used.

In any case, here is our testcase.
Note that there are no assertions - since its not the test that fails - just the index deletion on cleanup.

@ElasticsearchIntegrationTest.ClusterScope(scope = TEST, numClientNodes = 0, numDataNodes = 1)
public class ElasticBugsMoo extends ElasticsearchIntegrationTest
{
    private static final String INDEX = "bugindex";
    private final ObjectMapper json = new ObjectMapper();

    public ElasticBugsMoo()
    {
        json.configure(SerializationFeature.WRITE_DATES_AS_TIMESTAMPS, false);
        json.configure(SerializationFeature.WRITE_BIGDECIMAL_AS_PLAIN, true);
        json.configure(DeserializationFeature.USE_BIG_DECIMAL_FOR_FLOATS, true);
        json.configure(JsonGenerator.Feature.ESCAPE_NON_ASCII, true);
        json.registerModule(new JodaModule());
    }

    @Override
    protected Settings nodeSettings(int nodeOrdinal)
    {
        return settingsBuilder()
            .put("path.data", "target/elastic-test-data")
            .build();
    }

    private void index(String id, String type, String content) throws IOException
    {
        //noinspection unchecked
        index(INDEX, type, id, json.readValue(content, Map.class));
    }

    @Test
    public void deleteIndexFailedNotAcked() throws IOException
    {
        String settingsSource = "{\"analysis\":{\"analyzer\":{\"logistics_index\":{\"tokenizer\":\"whitespace\",\"filter\":[\"lowercase\"]},\"logistics_search\":{\"tokenizer\":\"whitespace\",\"filter\":[\"lowercase\"]},\"default_index\":{\"type\":\"combo\",\"deduplication\":\"true\",\"sub_analyzers\":[\"logistics_index\",\"standard\"]},\"default_search\":{\"type\":\"combo\",\"deduplication\":\"true\",\"sub_analyzers\":[\"logistics_search\",\"standard\"]}}},\"number_of_replicas\":0}";
        admin()
            .indices()
            .prepareCreate(INDEX)
            .setSettings(settingsSource)
            .execute()
            .actionGet();

        String propertiesSource = "{\"properties\":{\"contractualLocationCity\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"quantityUnitOfMeasure\":{\"index\":\"no\",\"type\":\"string\"},\"contractualLocationCountry\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"isAllocationNotInvoiced\":{\"type\":\"boolean\"},\"quotaStatusLabel\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"isFullyAllocated\":{\"type\":\"boolean\"},\"contractualLocation\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"allocatedQuantity\":{\"type\":\"double\"},\"quantityNormalisedUnitOfMeasure\":{\"index\":\"no\",\"type\":\"string\"},\"isInvoicedFinal\":{\"type\":\"boolean\"},\"quotaId\":{\"type\":\"long\"},\"counterParty\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"allocationStatus\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"quantity\":{\"type\":\"double\"},\"allocatedQuantityUnitOfMeasure\":{\"index\":\"no\",\"type\":\"string\"},\"customTokens\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"tradeRef\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"unallocatedQuantity\":{\"type\":\"double\"},\"contract\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"contractualLocationCode\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"shape\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"quotaStatus\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"invoiceStatus\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"unallocatedQuantityNormalisedUnitOfMeasure\":{\"index\":\"no\",\"type\":\"string\"},\"allocatedQuantityNormalised\":{\"type\":\"double\"},\"isActive\":{\"type\":\"boolean\"},\"shipmentDate\":{\"format\":\"date\",\"type\":\"date\"},\"completedDate\":{\"format\":\"date\",\"type\":\"date\"},\"groupCompany\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"allocationStatusLabel\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"invoiceQuantity\":{\"type\":\"double\"},\"resolvedIds\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"expectedSalesMonth\":{\"format\":\"date\",\"type\":\"date\"},\"expectedSalesLocationCity\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"isCancelled\":{\"type\":\"boolean\"},\"neptuneQuotaId\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"contractDutyPaid\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"unallocatedQuantityNormalised\":{\"type\":\"double\"},\"contractIncotermsCode\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"groupCompanyCode\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"grade\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"invoiceQuantityUnitOfMeasure\":{\"index\":\"no\",\"type\":\"string\"},\"unallocatedQuantityUnitOfMeasure\":{\"index\":\"no\",\"type\":\"string\"},\"counterPartyCode\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"allocatedQuantityNormalisedUnitOfMeasure\":{\"index\":\"no\",\"type\":\"string\"},\"isPurchase\":{\"type\":\"boolean\"},\"trafficOperatorFullName\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"groupCompanyId\":{\"include_in_all\":false,\"index\":\"not_analyzed\",\"type\":\"string\"},\"expectedSalesLocation\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"intentIncotermsCode\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"trafficOperatorSid\":{\"include_in_all\":false,\"index\":\"not_analyzed\",\"type\":\"string\"},\"quantityNormalised\":{\"type\":\"double\"},\"commodity\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"contractIncoterms\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"expectedSalesLocationCode\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"brand\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"quotaType\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"expectedSalesLocationCountry\":{\"index\":\"not_analyzed\",\"type\":\"string\"},\"quotaRef\":{\"index\":\"not_analyzed\",\"boost\":2.0,\"type\":\"string\"},\"comments\":{\"type\":\"string\"},\"intentIncoterms\":{\"index\":\"not_analyzed\",\"type\":\"string\"}}}";
        admin()
            .indices()
            .preparePutMapping(INDEX)
            .setType("quota")
            .setSource(propertiesSource)
            .execute()
            .actionGet();

        index("1563150401", "quota", "{\"allocatedQuantity\":1000.0000,\"allocatedQuantityNormalised\":1000.0000,\"allocatedQuantityNormalisedUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"allocatedQuantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"allocationStatus\":\"PARTIALLY_ALLOCATED\",\"allocationStatusLabel\":\"Partially Allocated\",\"brand\":\"ACME\u2122\",\"comments\":\"TIC-P.26884TSHS\",\"commodity\":\"0# (99.995%) sand\",\"completedDate\":\"2014-11-16\",\"contract\":\"contract\",\"contractDutyPaid\":null,\"counterParty\":\"Corporacion de Acero \\\"Corpacero\\\"\",\"counterPartyCode\":\"\u804DZ\uDB7C\uDF82L\uB86A\uDAE4\uDE90\",\"customTokens\":[\"Flat square\",\"99.995%\"],\"expectedSalesMonth\":\"2014-11-17\",\"grade\":\"99.97%\",\"groupCompany\":\"GROUP-COMPANY-NAME-\uD8AD\uDCA9\\u0003\u7CDF\uC753\uDB14\uDE39\uAEDB\u00FA\uE682'\u5720\",\"groupCompanyCode\":\"GROUP-COMPANY-CODE-\uD8AD\uDCA9\\u0003\u7CDF\uC753\uDB14\uDE39\uAEDB\u00FA\uE682'\u5720\",\"groupCompanyId\":\"D99DCC1027854A4A922C37DFCCA383DC\",\"invoiceQuantity\":1000.0000,\"invoiceQuantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"invoiceStatus\":\"NOTFINALINVOICED\",\"isActive\":true,\"isAllocationNotInvoiced\":false,\"isCancelled\":false,\"isFullyAllocated\":false,\"isInvoicedFinal\":false,\"isPurchase\":true,\"neptuneQuotaId\":\"neptune-quota-id\",\"quantity\":1000.0000,\"quantityNormalised\":1000.0000,\"quantityNormalisedUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"quantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"quotaId\":1563150401,\"quotaRef\":\"6775.2\",\"quotaStatus\":\"COMPLETED\",\"quotaStatusLabel\":\"Completed\",\"quotaType\":\"PURCHASE\",\"resolvedIds\":[\"2CBD832AD9BE44FBA0C8E70E0E7A529E\",\"0EAB028E816D458DA1F765C6374C9386\",\"02C11D517A2F49AD8A53F255659E9260\",\"D99DCC1027854A4A922C37DFCCA383DC\",\"1569C43411D24E61A9C7D40D98F106C8\",\"811FD5137CB04E67AE90B08E5D8DAA53\",\"8BFD8633E4214B60957A1357069EE0B3\",\"E75A29FBE34D4461A9C8E5951CD15207\",\"2269C24D7A7844F7A7DAFB763FC75EE8\",\"55C445000CA14A3AA8A15FE37AF59015\",\"532150BA73844BEBA101B4EED9D9AD97\",\"3410FEF0BCAC4C55B686E31738177DBB\",\"8EBB9138B839470393003185BCF9FE02\"],\"shape\":\"Flat(square)\",\"shipmentDate\":\"2014-12-02\",\"tradeRef\":\"edm-trade-id\",\"trafficOperatorFullName\":\"Unknown User\",\"trafficOperatorSid\":\"UNKNOWN-USER-SID-8EBB9138B839470393003185BCF9FE02\",\"unallocatedQuantity\":1000.0000,\"unallocatedQuantityNormalised\":1000.0000,\"unallocatedQuantityNormalisedUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"unallocatedQuantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\"}");
        index("1459932957", "quota", "{\"allocatedQuantity\":1000.0000,\"allocatedQuantityNormalised\":1000.0000,\"allocatedQuantityNormalisedUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"allocatedQuantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"allocationStatus\":\"PARTIALLY_ALLOCATED\",\"allocationStatusLabel\":\"Partially Allocated\",\"brand\":\"Any Brand\",\"comments\":\"comments...\",\"commodity\":\"\\f\uED97i\u0146+\u0438\",\"completedDate\":\"2014-11-16\",\"contract\":\"contract\",\"contractDutyPaid\":null,\"customTokens\":[],\"expectedSalesMonth\":\"2014-11-17\",\"grade\":null,\"groupCompany\":\"GROUP-COMPANY-NAME-\uD8AD\uDCA9\\u0003\u7CDF\uC753\uDB14\uDE39\uAEDB\u00FA\uE682'\u5720\",\"groupCompanyCode\":\"GROUP-COMPANY-CODE-\uD8AD\uDCA9\\u0003\u7CDF\uC753\uDB14\uDE39\uAEDB\u00FA\uE682'\u5720\",\"groupCompanyId\":\"D99DCC1027854A4A922C37DFCCA383DC\",\"invoiceQuantity\":1000.0000,\"invoiceQuantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"invoiceStatus\":\"NOTFINALINVOICED\",\"isActive\":true,\"isAllocationNotInvoiced\":false,\"isCancelled\":false,\"isFullyAllocated\":false,\"isInvoicedFinal\":false,\"isPurchase\":true,\"neptuneQuotaId\":\"neptune-quota-id\",\"quantity\":1000.0000,\"quantityNormalised\":1000.0000,\"quantityNormalisedUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"quantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"quotaId\":1459932957,\"quotaRef\":\"6775.1\",\"quotaStatus\":\"COMPLETED\",\"quotaStatusLabel\":\"Completed\",\"quotaType\":\"PURCHASE\",\"resolvedIds\":[\"F06881353B9D4756BE580C0931189A94\",\"39E34BCAED5E450892391204C6865816\",\"10AB18CA8AAD4EE0922D8BAE8DB35688\",\"64A670281F7A4F1499754F631C5B4251\",\"6B4987E5DC114C4D80B1B6EE1F8388E4\",\"423E598F4829480DBDC40D61DC54306E\",\"9647CA439B234C068DD93D542E8382EA\",\"D99DCC1027854A4A922C37DFCCA383DC\",\"19E31892366C4B4C9715BB6FA6843E9D\",\"F61B663E722444E4B48D62BB27CE8365\",\"532150BA73844BEBA101B4EED9D9AD97\",\"5DDCECD3E741439F9BC60A6B9D03CF74\",\"C945503A0C8B48209781634BE290FA86\"],\"shape\":\"Any Shape\",\"shipmentDate\":\"2014-12-02\",\"tradeRef\":\"edm-trade-id\",\"trafficOperatorFullName\":\"Unknown User\",\"trafficOperatorSid\":\"UNKNOWN-USER-SID-423E598F4829480DBDC40D61DC54306E\",\"unallocatedQuantity\":1000.0000,\"unallocatedQuantityNormalised\":1000.0000,\"unallocatedQuantityNormalisedUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"unallocatedQuantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\"}");
        index("688731920", "quota",
            "{\"allocatedQuantity\":1000.0000,\"allocatedQuantityNormalised\":1000.0000,\"allocatedQuantityNormalisedUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"allocatedQuantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"allocationStatus\":\"PARTIALLY_ALLOCATED\",\"allocationStatusLabel\":\"Partially Allocated\",\"brand\":\"Any Brand\",\"comments\":\"comments...\",\"commodity\":\"\\f\uED97i\u0146+\u0438\",\"completedDate\":\"2014-11-16\",\"contract\":\"contract\",\"contractDutyPaid\":null,\"customTokens\":[],\"expectedSalesMonth\":\"2014-11-17\",\"grade\":null,\"groupCompany\":\"GROUP-COMPANY-NAME-\uD8AD\uDCA9\\u0003\u7CDF\uC753\uDB14\uDE39\uAEDB\u00FA\uE682'\u5720\",\"groupCompanyCode\":\"GROUP-COMPANY-CODE-\uD8AD\uDCA9\\u0003\u7CDF\uC753\uDB14\uDE39\uAEDB\u00FA\uE682'\u5720\",\"groupCompanyId\":\"D99DCC1027854A4A922C37DFCCA383DC\",\"invoiceQuantity\":1000.0000,\"invoiceQuantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"invoiceStatus\":\"NOTFINALINVOICED\",\"isActive\":true,\"isAllocationNotInvoiced\":false,\"isCancelled\":false,\"isFullyAllocated\":false,\"isInvoicedFinal\":false,\"isPurchase\":true,\"neptuneQuotaId\":\"neptune-quota-id\",\"quantity\":1000.0000,\"quantityNormalised\":1000.0000,\"quantityNormalisedUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"quantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"quotaId\":688731920,\"quotaRef\":\"6775.3\",\"quotaStatus\":\"COMPLETED\",\"quotaStatusLabel\":\"Completed\",\"quotaType\":\"PURCHASE\",\"resolvedIds\":[\"39E34BCAED5E450892391204C6865816\",\"E01323877943405A8717807EC25ADBDE\",\"532150BA73844BEBA101B4EED9D9AD97\",\"5D2F1F0B6B09476BA7657F436C279207\",\"8A2F58C04C994D61A087D3F727EF73C6\",\"8054C6A5A0D6410D94B466DE013EECCE\",\"D166F80523A840FFB18CA85243DDB112\",\"C065B002179C481BBC1BF80FE87642BF\",\"096144BAFCDE416D89D0A5107163D11A\",\"D99DCC1027854A4A922C37DFCCA383DC\",\"BBF3316A0A1342EFB0AB2AE855D749DD\",\"EE4A459BED5C42928B60A357BA6D1363\",\"3994E00006CA49F78BCFB017DD5F01C4\"],\"shape\":\"Any Shape\",\"shipmentDate\":\"2014-12-02\",\"tradeRef\":\"edm-trade-id\",\"trafficOperatorFullName\":\"Unknown User\",\"trafficOperatorSid\":\"UNKNOWN-USER-SID-E01323877943405A8717807EC25ADBDE\",\"unallocatedQuantity\":1000.0000,\"unallocatedQuantityNormalised\":1000.0000,\"unallocatedQuantityNormalisedUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\",\"unallocatedQuantityUnitOfMeasure\":\"\uE697\uDB31\uDD41\\u0013\u00A3\u04C8\uE215\"}");

        refresh();

        String searchSource1 = "{\"from\":0,\"size\":1000,\"query\":{\"filtered\":{\"query\":{\"bool\":{\"must\":[{\"prefix\":{\"_all\":{\"prefix\":\"0#\"}}},{\"prefix\":{\"_all\":{\"prefix\":\"(99.995%)\"}}},{\"prefix\":{\"_all\":{\"prefix\":\"sand\"}}}]}},\"filter\":{\"and\":{\"filters\":[{\"type\":{\"value\":\"quota\"}},{\"terms\":{\"groupCompanyId\":[\"D99DCC1027854A4A922C37DFCCA383DC\",\"NO_GROUP_COMPANY\"]}}]}}}},\"aggregations\":{\"aggregated_quantity_allocatedQuantityNormalised\":{\"sum\":{\"field\":\"allocatedQuantityNormalised\"}},\"aggregated_quantity_quantityNormalised\":{\"sum\":{\"field\":\"quantityNormalised\"}},\"aggregated_quantity_unallocatedQuantityNormalised\":{\"sum\":{\"field\":\"unallocatedQuantityNormalised\"}}}}";
        String searchSource2 = "{\"from\":0,\"size\":1000,\"query\":{\"filtered\":{\"query\":{\"bool\":{\"must\":{\"prefix\":{\"_all\":{\"prefix\":\"tic-p.26884tshs\"}}}}},\"filter\":{\"and\":{\"filters\":[{\"type\":{\"value\":\"quota\"}},{\"terms\":{\"groupCompanyId\":[\"D99DCC1027854A4A922C37DFCCA383DC\",\"NO_GROUP_COMPANY\"]}}]}}}},\"aggregations\":{\"aggregated_quantity_allocatedQuantityNormalised\":{\"sum\":{\"field\":\"allocatedQuantityNormalised\"}},\"aggregated_quantity_quantityNormalised\":{\"sum\":{\"field\":\"quantityNormalised\"}},\"aggregated_quantity_unallocatedQuantityNormalised\":{\"sum\":{\"field\":\"unallocatedQuantityNormalised\"}}}}";
        String searchSource3 = "{\"from\":0,\"size\":1000,\"query\":{\"filtered\":{\"query\":{\"bool\":{\"must\":[{\"prefix\":{\"_all\":{\"prefix\":\"corporacion\"}}},{\"prefix\":{\"_all\":{\"prefix\":\"de\"}}},{\"prefix\":{\"_all\":{\"prefix\":\"acero\"}}},{\"prefix\":{\"_all\":{\"prefix\":\"\\\"corpacero\\\"\"}}}]}},\"filter\":{\"and\":{\"filters\":[{\"type\":{\"value\":\"quota\"}},{\"terms\":{\"groupCompanyId\":[\"D99DCC1027854A4A922C37DFCCA383DC\",\"NO_GROUP_COMPANY\"]}}]}}}},\"aggregations\":{\"aggregated_quantity_allocatedQuantityNormalised\":{\"sum\":{\"field\":\"allocatedQuantityNormalised\"}},\"aggregated_quantity_quantityNormalised\":{\"sum\":{\"field\":\"quantityNormalised\"}},\"aggregated_quantity_unallocatedQuantityNormalised\":{\"sum\":{\"field\":\"unallocatedQuantityNormalised\"}}}}";
        String searchSource4 = "{\"from\":0,\"size\":1000,\"query\":{\"filtered\":{\"query\":{\"bool\":{\"must\":{\"prefix\":{\"_all\":{\"prefix\":\"99.97%\"}}}}},\"filter\":{\"and\":{\"filters\":[{\"type\":{\"value\":\"quota\"}},{\"terms\":{\"groupCompanyId\":[\"D99DCC1027854A4A922C37DFCCA383DC\",\"NO_GROUP_COMPANY\"]}}]}}}},\"aggregations\":{\"aggregated_quantity_allocatedQuantityNormalised\":{\"sum\":{\"field\":\"allocatedQuantityNormalised\"}},\"aggregated_quantity_quantityNormalised\":{\"sum\":{\"field\":\"quantityNormalised\"}},\"aggregated_quantity_unallocatedQuantityNormalised\":{\"sum\":{\"field\":\"unallocatedQuantityNormalised\"}}}}";
        String searchSource5 = "{\"from\":0,\"size\":1000,\"query\":{\"filtered\":{\"query\":{\"bool\":{\"must\":{\"prefix\":{\"_all\":{\"prefix\":\"acme\u2122\"}}}}},\"filter\":{\"and\":{\"filters\":[{\"type\":{\"value\":\"quota\"}},{\"terms\":{\"groupCompanyId\":[\"D99DCC1027854A4A922C37DFCCA383DC\",\"NO_GROUP_COMPANY\"]}}]}}}},\"aggregations\":{\"aggregated_quantity_allocatedQuantityNormalised\":{\"sum\":{\"field\":\"allocatedQuantityNormalised\"}},\"aggregated_quantity_quantityNormalised\":{\"sum\":{\"field\":\"quantityNormalised\"}},\"aggregated_quantity_unallocatedQuantityNormalised\":{\"sum\":{\"field\":\"unallocatedQuantityNormalised\"}}}}";
        String searchSource6 = "{\"from\":0,\"size\":1000,\"query\":{\"filtered\":{\"query\":{\"bool\":{\"must\":{\"prefix\":{\"_all\":{\"prefix\":\"flat(square)\"}}}}},\"filter\":{\"and\":{\"filters\":[{\"type\":{\"value\":\"quota\"}},{\"terms\":{\"groupCompanyId\":[\"D99DCC1027854A4A922C37DFCCA383DC\",\"NO_GROUP_COMPANY\"]}}]}}}},\"aggregations\":{\"aggregated_quantity_allocatedQuantityNormalised\":{\"sum\":{\"field\":\"allocatedQuantityNormalised\"}},\"aggregated_quantity_quantityNormalised\":{\"sum\":{\"field\":\"quantityNormalised\"}},\"aggregated_quantity_unallocatedQuantityNormalised\":{\"sum\":{\"field\":\"unallocatedQuantityNormalised\"}}}}";
        String searchSource7 = "{\"from\":0,\"size\":1000,\"query\":{\"filtered\":{\"query\":{\"bool\":{\"must\":{\"prefix\":{\"_all\":{\"prefix\":\"99.97\"}}}}},\"filter\":{\"and\":{\"filters\":[{\"type\":{\"value\":\"quota\"}},{\"terms\":{\"groupCompanyId\":[\"D99DCC1027854A4A922C37DFCCA383DC\",\"NO_GROUP_COMPANY\"]}}]}}}},\"aggregations\":{\"aggregated_quantity_allocatedQuantityNormalised\":{\"sum\":{\"field\":\"allocatedQuantityNormalised\"}},\"aggregated_quantity_quantityNormalised\":{\"sum\":{\"field\":\"quantityNormalised\"}},\"aggregated_quantity_unallocatedQuantityNormalised\":{\"sum\":{\"field\":\"unallocatedQuantityNormalised\"}}}}";
        String searchSource8 = "{\"from\":0,\"size\":1000,\"query\":{\"filtered\":{\"query\":{\"bool\":{\"must\":{\"prefix\":{\"_all\":{\"prefix\":\"99.995\"}}}}},\"filter\":{\"and\":{\"filters\":[{\"type\":{\"value\":\"quota\"}},{\"terms\":{\"groupCompanyId\":[\"D99DCC1027854A4A922C37DFCCA383DC\",\"NO_GROUP_COMPANY\"]}}]}}}},\"aggregations\":{\"aggregated_quantity_allocatedQuantityNormalised\":{\"sum\":{\"field\":\"allocatedQuantityNormalised\"}},\"aggregated_quantity_quantityNormalised\":{\"sum\":{\"field\":\"quantityNormalised\"}},\"aggregated_quantity_unallocatedQuantityNormalised\":{\"sum\":{\"field\":\"unallocatedQuantityNormalised\"}}}}";
        String searchSource9 = "{\"from\":0,\"size\":1000,\"query\":{\"filtered\":{\"query\":{\"bool\":{\"must\":{\"prefix\":{\"_all\":{\"prefix\":\"99.995%\"}}}}},\"filter\":{\"and\":{\"filters\":[{\"type\":{\"value\":\"quota\"}},{\"terms\":{\"groupCompanyId\":[\"D99DCC1027854A4A922C37DFCCA383DC\",\"NO_GROUP_COMPANY\"]}}]}}}},\"aggregations\":{\"aggregated_quantity_allocatedQuantityNormalised\":{\"sum\":{\"field\":\"allocatedQuantityNormalised\"}},\"aggregated_quantity_quantityNormalised\":{\"sum\":{\"field\":\"quantityNormalised\"}},\"aggregated_quantity_unallocatedQuantityNormalised\":{\"sum\":{\"field\":\"unallocatedQuantityNormalised\"}}}}";
        String searchSource10 = "{\"from\":0,\"size\":1000,\"query\":{\"filtered\":{\"query\":{\"bool\":{\"must\":{\"prefix\":{\"_all\":{\"prefix\":\"0#\"}}}}},\"filter\":{\"and\":{\"filters\":[{\"type\":{\"value\":\"quota\"}},{\"terms\":{\"groupCompanyId\":[\"D99DCC1027854A4A922C37DFCCA383DC\",\"NO_GROUP_COMPANY\"]}}]}}}},\"aggregations\":{\"aggregated_quantity_allocatedQuantityNormalised\":{\"sum\":{\"field\":\"allocatedQuantityNormalised\"}},\"aggregated_quantity_quantityNormalised\":{\"sum\":{\"field\":\"quantityNormalised\"}},\"aggregated_quantity_unallocatedQuantityNormalised\":{\"sum\":{\"field\":\"unallocatedQuantityNormalised\"}}}}";
        String searchSource11 = "{\"from\":0,\"size\":1000,\"query\":{\"filtered\":{\"query\":{\"bool\":{\"must\":{\"prefix\":{\"_all\":{\"prefix\":\"nofindy\"}}}}},\"filter\":{\"and\":{\"filters\":[{\"type\":{\"value\":\"quota\"}},{\"terms\":{\"groupCompanyId\":[\"D99DCC1027854A4A922C37DFCCA383DC\",\"NO_GROUP_COMPANY\"]}}]}}}},\"aggregations\":{\"aggregated_quantity_allocatedQuantityNormalised\":{\"sum\":{\"field\":\"allocatedQuantityNormalised\"}},\"aggregated_quantity_quantityNormalised\":{\"sum\":{\"field\":\"quantityNormalised\"}},\"aggregated_quantity_unallocatedQuantityNormalised\":{\"sum\":{\"field\":\"unallocatedQuantityNormalised\"}}}}";

        List<String> searchSources = newArrayList(
            searchSource1,
            searchSource2,
            searchSource3,
            searchSource4,
            searchSource5,
            searchSource6,
            searchSource7,
            searchSource8,
            searchSource9,
            searchSource10,
            searchSource11
        );

        for (String searchSource : searchSources)
        {
            SearchResponse response = client()
                .prepareSearch(INDEX)
                .setSource(searchSource)
                .execute()
                .actionGet();
        }
    }

    private String prettyPrint(String aggregationSource) throws IOException
    {
        return json.writerWithDefaultPrettyPrinter().writeValueAsString(json.readValue(aggregationSource, Map.class));
    }
}

@mikemccand
Copy link
Contributor

@nickminutello indeed that test only creates a tiny index.

In #8528 we were seeing this same issue (not caused by #8405) and as far as I can tell it was just a "IO system is too slow", i.e. there are not apparent thread deadlocks. It's just that the flush took > 30 seconds ... so your theory that your heavily loaded build box could lead to this timeout makes sense.

The time is DeleteIndexRequest.setTimeout() but that's being created & sent/ack'd inside TestCluster.wipeIndices and I don't think TestCluster has a way to set the timeout on that request.

You could also try disabling check index for your test (set MockFSDirectoryService.CHECK_INDEX_ON_CLOSE to false in your settings when you create the index)... that prevents the test infra from doing a flush after the test finishes.

@nickminutello
Copy link
Author

Is the 30s a default timeout for all requests? Is the default timeout configurable?

I will try disable the check to see if that helps.

@nickminutello
Copy link
Author

I havent had a chance to try disabling the check yet.
But where does this 30s come from?

@mikemccand
Copy link
Contributor

But where does this 30s come from?

I explained this above:

The time is DeleteIndexRequest.setTimeout() but that's being created & sent/ack'd inside TestCluster.wipeIndices and I don't think TestCluster has a way to set the timeout on that request.

@nickminutello
Copy link
Author

I guess I am not expressing my question properly - or I am not understanding your answer - either way, apologies and thanks for the patience.

I guess what I am trying to say is I dont see any explicit call to DeleteIndexRequest.setTimeout()
What I see is:

 assertAcked(client().admin().indices().prepareDelete(indices));

So it looks to me like no timeout is being set?
So my question is where is it being set/defaulted?

Sorry if I am being slow...

@mikemccand
Copy link
Contributor

So my question is where is it being set/defaulted?

DeleteIndexRequest inherits setTimeout from MasterNodeOperationRequest, and if you look at the sources for that class you see it has an instance variable "timeout" that is initialized to 30 sec.

You could perhaps just invoke the delete index from the end of your test case, and at that point set a larger timeout?

@clintongormley
Copy link

No more info provided. Closing for now

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@s1monw s1monw

Labels
feedback_needed >test Issues or PRs that are addressing/adding tests
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@clintongormley @nickminutello @mikemccand @javanna @s1monw