[CI] SearchIT.testCountAllIndicesNoQuery failed on master #35644

dimitris-athanasiou · 2018-11-16T15:39:10Z

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.

The text was updated successfully, but these errors were encountered:

elasticmachine · 2018-11-16T15:39:11Z

Pinging @elastic/es-search-aggs

cbuescher · 2018-12-11T14:36:25Z

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 · 2018-12-11T14:39:26Z

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 · 2018-12-11T14:43:20Z

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

Adding logging to confirm the suspicion that there might be another old index lingering around in the test cluster in cases where this test occasionally fails.

cbuescher · 2018-12-11T18:09:14Z

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.

* elastic/master: (36 commits) Add check for minimum required Docker version (elastic#36497) Minor search controller changes (elastic#36479) Add default methods to DocValueFormat (elastic#36480) Fix the mixed cluster REST test explain/11_basic_with_types. Modify `BigArrays` to take name of circuit breaker (elastic#36461) Move LoggedExec to minimumRuntime source set (elastic#36453) added 6.5.4 version Add test logging for elastic#35644 Tests- added helper methods to ESRestTestCase for checking warnings (elastic#36443) SQL: move requests' parameters to requests JSON body (elastic#36149) [Zen2] Respect the no_master_block setting (elastic#36478) Require soft-deletes when access changes snapshot (elastic#36446) Switch more tests to zen2 (elastic#36367) [Painless] Add extensive tests for def to primitive casts (elastic#36455) Add setting to bypass Rollover action (elastic#36235) Try running CI against Zulu (elastic#36391) [DOCS] Reworked the shard allocation filtering info. (elastic#36456) Log [initial_master_nodes] on formation failure (elastic#36466) converting ForbiddenPatternsTask to .java (elastic#36194) fixed typo ...

pgomulka · 2018-12-17T12:38:23Z

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 · 2018-12-28T11:59:40Z

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

hendrikmuhs · 2019-01-10T09:30:13Z

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.

This change ensures that TasksIT#testGetValidTask and ReindexIT#testReindexTask don't leave a non-completed task on the cluster when they finish. Closes elastic#35644

) This change ensures that TasksIT#testGetValidTask and ReindexIT#testReindexTask don't leave a non-completed task on the cluster when they finish. Closes #35644

This logging was added to get better insight into elastic#35644 which was closed by

This logging was added to get better insight into #35644 which was closed by #37302 and can be removed now.

dimitris-athanasiou added :Search/Search Search-related issues that do not fall into other categories >test-failure Triaged test failures from CI v7.0.0 labels Nov 16, 2018

cbuescher self-assigned this Dec 11, 2018

cbuescher pushed a commit that referenced this issue Dec 11, 2018

Add test logging for #35644

c595a73

Adding logging to confirm the suspicion that there might be another old index lingering around in the test cluster in cases where this test occasionally fails.

cbuescher mentioned this issue Dec 17, 2018

[CI] ClusterClientIT failure #35450

Closed

jimczi mentioned this issue Jan 10, 2019

[TEST] Awaits tasks termination in the RestHighLevelClient tests #37302

Merged

jimczi closed this as completed in #37302 Jan 11, 2019

colings86 added v7.0.0-beta1 and removed v7.0.0 labels Feb 7, 2019

jtibshirani mentioned this issue Jun 12, 2019

testCountAllIndicesNoQuery fails #39754

Closed

cbuescher pushed a commit to cbuescher/elasticsearch that referenced this issue Apr 2, 2020

[Tests] Remove unneeded test logging

e2bc52c

This logging was added to get better insight into elastic#35644 which was closed by

cbuescher mentioned this issue Apr 2, 2020

[Tests] Remove unneeded test logging from SearchIT #54634

Merged

cbuescher pushed a commit that referenced this issue Apr 2, 2020

[Tests] Remove unneeded test logging (#54634)

9046f77

This logging was added to get better insight into #35644 which was closed by #37302 and can be removed now.

cbuescher pushed a commit that referenced this issue Apr 2, 2020

[Tests] Remove unneeded test logging (#54634)

4882bb5

This logging was added to get better insight into #35644 which was closed by #37302 and can be removed now.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[CI] SearchIT.testCountAllIndicesNoQuery failed on master #35644

[CI] SearchIT.testCountAllIndicesNoQuery failed on master #35644

dimitris-athanasiou commented Nov 16, 2018

elasticmachine commented Nov 16, 2018

cbuescher commented Dec 11, 2018 •

edited

Loading

cbuescher commented Dec 11, 2018

cbuescher commented Dec 11, 2018

cbuescher commented Dec 11, 2018

pgomulka commented Dec 17, 2018 •

edited

Loading

javanna commented Dec 28, 2018

hendrikmuhs commented Jan 10, 2019

[CI] SearchIT.testCountAllIndicesNoQuery failed on master #35644

[CI] SearchIT.testCountAllIndicesNoQuery failed on master #35644

Comments

dimitris-athanasiou commented Nov 16, 2018

elasticmachine commented Nov 16, 2018

cbuescher commented Dec 11, 2018 • edited Loading

cbuescher commented Dec 11, 2018

cbuescher commented Dec 11, 2018

cbuescher commented Dec 11, 2018

pgomulka commented Dec 17, 2018 • edited Loading

javanna commented Dec 28, 2018

hendrikmuhs commented Jan 10, 2019

cbuescher commented Dec 11, 2018 •

edited

Loading

pgomulka commented Dec 17, 2018 •

edited

Loading