[CI] SearchIT.testCountAllIndicesNoQuery failed on master

[dimitris-athanasiou]

Build: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+multijob-unix-compatibility/os=amazon/62/console

Failure:

> Throwable #1: java.lang.AssertionError: expected:<12> but was:<13>
   > 	at __randomizedtesting.SeedInfo.seed([16EC17CB7A0CB706:E3C7CEBDF03F1BEC]:0)
   > 	at org.elasticsearch.client.SearchIT.testCountAllIndicesNoQuery(SearchIT.java:1257)
   > 	at java.lang.Thread.run(Thread.java:748)

Reproduce with:

./gradlew :client:rest-high-level:integTestRunner -Dtests.seed=16EC17CB7A0CB706 -Dtests.class=org.elasticsearch.client.SearchIT -Dtests.method="testCountAllIndicesNoQuery" -Dtests.security.manager=true -Dtests.locale=lv -Dtests.timezone=EAT -Dcompiler.java=11 -Druntime.java=8

Could not reproduce locally.

[elasticmachine]

Pinging @elastic/es-search-aggs

[cbuescher]

I found two similar looking ones:
https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+intake/458/console (<- build info seems to be lost)
https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.x+release-tests/162/console

[cbuescher]

The error in the later log looks similar to the one from three weeks ago:

   > Throwable #1: java.lang.AssertionError: expected:<12> but was:<13>
   > 	at __randomizedtesting.SeedInfo.seed([AF2649E4184052C0:5A0D90929273FE2A]:0)
   > 	at org.elasticsearch.client.SearchIT.testCountAllIndicesNoQuery(SearchIT.java:1273)
   > 	at java.lang.Thread.run(Thread.java:748)

[cbuescher]

Possibly related to #35450 which is caused by a sneaky .tasks index hanging around from somewhere.

[cbuescher]

I added some logging to the test in c595a73 that hopefully helps to confirm the above suspicion about the lingering index once this fails again.

[pgomulka]

it failed on https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+multijob-unix-compatibility/os=amazon/124/console

does not reproduce for me

REPRODUCE WITH: ./gradlew :client:rest-high-level:integTestRunner \
  -Dtests.seed=21B34499ECB5F029 \
  -Dtests.class=org.elasticsearch.client.SearchIT \
  -Dtests.method="testCountAllIndicesNoQuery" \
  -Dtests.security.manager=true \
  -Dtests.locale=hu \
  -Dtests.timezone=Etc/GMT+2 \
  -Dcompiler.java=11 \
  -Druntime.java=8

Thanks to @cbuescher extra logging we can see:

1> [2018-12-17T09:57:59,687][INFO ][o.e.c.SearchIT           ] [testCountAllIndicesNoQuery] Unexpected hit count, was expecting 12 hits but got: {"took":1,"timed_out":false,"_shards":{"total":6,"successful":6,"skipped":0,"failed":0},"hits":{"total":{"value":13,"relation":"eq"},"max_score":1.0,"hits":[{"_index":".tasks","_type":"task","_id":"gYe36U9WTSGVCPUHSmbXEg:7480","_score":1.0,"_source":{"completed":true,"task":{"node":"gYe36U9WTSGVCPUHSmbXEg","id":7480,"type":"transport","action":"indices:data/write/reindex","status":{"total":2,"updated":0,"created":0,"deleted":0,"batches":1,"version_conflicts":0,"noops":0,"retries":{"bulk":0,"search":0},"throttled_millis":0,"requests_per_second":-1.0,"canceled":"by user request","throttled_until_millis":0},"description":"reindex from [source1] to [dest]","start_time_in_millis":1545047819540,"running_time_in_nanos":60002806289,"cancellable":true,"headers":{}},"response":{"took":60002,"timed_out":false,"total":2,"updated":0,"created":0,"deleted":0,"batches":1,"version_conflicts":0,"noops":0,"retries":{"bulk":0,"search":0},"throttled":"0s","throttled_millis":0,"requests_per_second":-1.0,"canceled":"by user request","throttled_until":"0s","throttled_until_millis":0,"failures":[]}}},{"_index":"index","_type":"type","_id":"1","_score":1.0,"_source":{"type":"type1","num":10,"num2":50}},{"_index":"index","_type":"type","_id":"2","_score":1.0,"_source":{"type":"type1","num":20,"num2":40}},{"_index":"index","_type":"type","_id":"3","_score":1.0,"_source":{"type":"type1","num":50,"num2":35}},{"_index":"index","_type":"type","_id":"4","_score":1.0,"_source":{"type":"type2","num":100,"num2":10}},{"_index":"index","_type":"type","_id":"5","_score":1.0,"_source":{"type":"type2","num":100,"num2":10}},{"_index":"index1","_type":"_doc","_id":"1","_score":1.0,"_source":{"field":"value1","rating":7}},{"_index":"index1","_type":"_doc","_id":"2","_score":1.0,"_source":{"field":"value2"}},{"_index":"index2","_type":"_doc","_id":"3","_score":1.0,"_source":{"field":"value1","rating":"good"}},{"_index":"index2","_type":"_doc","_id":"4","_score":1.0,"_source":{"field":"value2"}},{"_index":"index3","_type":"_doc","_id":"5","_score":1.0,"_source":{"field":"value1"}},{"_index":"index3","_type":"_doc","_id":"6","_score":1.0,"_source":{"field":"value2"}},{"_index":"index4","_type":"_doc","_id":"1","_score":1.0,"_source":{"field1":"value1","field2":"value2"}}]}}

which confirms that .tasks index with one document is present when it was not expected to be

    "hits": [
      {
        "_index": ".tasks",
        "_type": "task",
        "_id": "gYe36U9WTSGVCPUHSmbXEg:7480",
...

[javanna]

another one: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.x+periodic/435/console

[hendrikmuhs]

Failed for me on a PR-build, captured the following log:

{
  "took": 2,
  "timed_out": false,
  "_shards": {
    "total": 6,
    "successful": 6,
    "skipped": 0,
    "failed": 0
  },
  "hits": {
    "total": {
      "value": 13,
      "relation": "eq"
    },
    "max_score": 1.0,
    "hits": [
      {
        "_index": ".tasks",
        "_type": "task",
        "_id": "3Mgmbr-jSiy4WiNGBFJJ3w:8266",
        "_score": 1.0,
        "_source": {
          "completed": true,
          "task": {
            "node": "3Mgmbr-jSiy4WiNGBFJJ3w",
            "id": 8266,
            "type": "transport",
            "action": "indices:data/write/reindex",
            "status": {
              "total": 2,
              "updated": 0,
              "created": 0,
              "deleted": 0,
              "batches": 1,
              "version_conflicts": 0,
              "noops": 0,
              "retries": {
                "bulk": 0,
                "search": 0
              },
              "throttled_millis": 0,
              "requests_per_second": -1.0,
              "canceled": "by user request",
              "throttled_until_millis": 0
            },
            "description": "reindex from [source1] to [dest][_doc]",
            "start_time_in_millis": 1547111508360,
            "running_time_in_nanos": 60008416819,
            "cancellable": true,
            "headers": {
              
            }
          },
          "response": {
            "took": 60005,
            "timed_out": false,
            "total": 2,
            "updated": 0,
            "created": 0,
            "deleted": 0,
            "batches": 1,
            "version_conflicts": 0,
            "noops": 0,
            "retries": {
              "bulk": 0,
              "search": 0
            },
            "throttled": "0s",
            "throttled_millis": 0,
            "requests_per_second": -1.0,
            "canceled": "by user request",
            "throttled_until": "0s",
            "throttled_until_millis": 0,
            "failures": [
              
            ]
          }
        }
      },
      {
        "_index": "index",
        "_type": "type",
        "_id": "1",
        "_score": 1.0,
        "_source": {
          "type": "type1",
          "num": 10,
          "num2": 50
        }
      },
      {
        "_index": "index",
        "_type": "type",
        "_id": "2",
        "_score": 1.0,
        "_source": {
          "type": "type1",
          "num": 20,
          "num2": 40
        }
      },
      {
        "_index": "index",
        "_type": "type",
        "_id": "3",
        "_score": 1.0,
        "_source": {
          "type": "type1",
          "num": 50,
          "num2": 35
        }
      },
      {
        "_index": "index",
        "_type": "type",
        "_id": "4",
        "_score": 1.0,
        "_source": {
          "type": "type2",
          "num": 100,
          "num2": 10
        }
      },
      {
        "_index": "index",
        "_type": "type",
        "_id": "5",
        "_score": 1.0,
        "_source": {
          "type": "type2",
          "num": 100,
          "num2": 10
        }
      },
      {
        "_index": "index1",
        "_type": "_doc",
        "_id": "1",
        "_score": 1.0,
        "_source": {
          "field": "value1",
          "rating": 7
        }
      },
      {
        "_index": "index1",
        "_type": "_doc",
        "_id": "2",
        "_score": 1.0,
        "_source": {
          "field": "value2"
        }
      },
      {
        "_index": "index2",
        "_type": "_doc",
        "_id": "3",
        "_score": 1.0,
        "_source": {
          "field": "value1",
          "rating": "good"
        }
      },
      {
        "_index": "index2",
        "_type": "_doc",
        "_id": "4",
        "_score": 1.0,
        "_source": {
          "field": "value2"
        }
      },
      {
        "_index": "index3",
        "_type": "_doc",
        "_id": "5",
        "_score": 1.0,
        "_source": {
          "field": "value1"
        }
      },
      {
        "_index": "index3",
        "_type": "_doc",
        "_id": "6",
        "_score": 1.0,
        "_source": {
          "field": "value2"
        }
      },
      {
        "_index": "index4",
        "_type": "_doc",
        "_id": "1",
        "_score": 1.0,
        "_source": {
          "field1": "value1",
          "field2": "value2"
        }
      }
    ]
  }
}

Without any knowledge about the test, the .tasks index doesn't really fit in the output.