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.

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

[BUG] :rest-api-spec:yamlRestTest org.opensearch.test.rest.ClientYamlTestSuiteIT intermittent failure #1817

Closed
dblock opened this issue Dec 28, 2021 · 3 comments · Fixed by #5652
Assignees
Labels
bug Something isn't working flaky-test Random test failure that succeeds on second run

Comments

@dblock
Copy link
Member

dblock commented Dec 28, 2021

Describe the bug

> Task :rest-api-spec:yamlRestTest

REPRODUCE WITH: ./gradlew ':rest-api-spec:yamlRestTest' --tests "org.opensearch.test.rest.ClientYamlTestSuiteIT" -Dtests.method="test {p0=search.aggregation/20_terms/string profiler via global ordinals}" -Dtests.seed=7348AFE0A0334C38 -Dtests.security.manager=true -Dtests.jvm.argline="-XX:TieredStopAtLevel=1 -XX:ReservedCodeCacheSize=64m" -Dtests.locale=ar-MA -Dtests.timezone=Indian/Chagos -Druntime.java=17

org.opensearch.test.rest.ClientYamlTestSuiteIT > test {p0=search.aggregation/20_terms/string profiler via global ordinals} FAILED
    java.lang.AssertionError: Failure at [search.aggregation/20_terms:863]: profile.shards.0.aggregations.0.debug.segments_with_multi_valued_ords didn't match expected value:
    profile.shards.0.aggregations.0.debug.segments_with_multi_valued_ords: expected Integer [0] but was Integer [1]
        at __randomizedtesting.SeedInfo.seed([7348AFE0A0334C38:FB1C903A0ECF21C0]:0)
        at org.opensearch.test.rest.yaml.OpenSearchClientYamlSuiteTestCase.executeSection(OpenSearchClientYamlSuiteTestCase.java:442)
        at org.opensearch.test.rest.yaml.OpenSearchClientYamlSuiteTestCase.test(OpenSearchClientYamlSuiteTestCase.java:415)
        at jdk.internal.reflect.GeneratedMethodAccessor12.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:568)
        at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
        at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
        at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
        at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
        at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.base/java.lang.Thread.run(Thread.java:833)

        Caused by:
        java.lang.AssertionError: profile.shards.0.aggregations.0.debug.segments_with_multi_valued_ords didn't match expected value:
        profile.shards.0.aggregations.0.debug.segments_with_multi_valued_ords: expected Integer [0] but was Integer [1]
            at org.opensearch.test.rest.yaml.section.MatchAssertion.doAssert(MatchAssertion.java:115)
            at org.opensearch.test.rest.yaml.section.Assertion.execute(Assertion.java:89)
            at org.opensearch.test.rest.yaml.OpenSearchClientYamlSuiteTestCase.executeSection(OpenSearchClientYamlSuiteTestCase.java:431)
            ... 36 more


Additional context

Coming from #1816 (comment)

https://ci.opensearch.org/logs/ci/workflow/OpenSearch_CI/PR_Checks/Gradle_Check/gradle_check_1701.log

@dbwiddis
Copy link
Member

Relevant tests

Code branches for getLeafCollector() should result in only one possible value > 0. Two test cases are for each type

test_1:

- gt: { profile.shards.0.aggregations.0.debug.segments_with_single_valued_ords: 0 }
- match: { profile.shards.0.aggregations.0.debug.segments_with_multi_valued_ords: 0 }

test_3:

- match: { profile.shards.0.aggregations.0.debug.segments_with_single_valued_ords: 0 }
- gt: { profile.shards.0.aggregations.0.debug.segments_with_multi_valued_ords: 0 }

However, stash dump shows both have a value of 1:

  1>                 "debug" : {
  1>                   "segments_with_multi_valued_ords" : 1,
  1>                   "collection_strategy" : "dense",
  1>                   "segments_with_single_valued_ords" : 1,
  1>                   "deferred_aggregators" : [
  1>                     "max_number"
  1>                   ],
  1>                   "result_strategy" : "terms",
  1>                   "has_filter" : false
  1>                 },

The max aggregator shows it has built two leaf collectors:

  1>                 "children" : [
  1>                   {
  1>                     "type" : "MaxAggregator",
  1>                     "description" : "max_number",
  1>                     "time_in_nanos" : 166539,
  1>                     "breakdown" : {
  1>                       "reduce" : 0,
  1>                       "post_collection_count" : 1,
  1>                       "build_leaf_collector" : 104055,
  1>                       "build_aggregation" : 12091,
  1>                       "build_aggregation_count" : 1,
  1>                       "build_leaf_collector_count" : 2,
  1>                       "post_collection" : 1241,
  1>                       "initialize" : 6207,
  1>                       "initialize_count" : 1,
  1>                       "reduce_count" : 0,
  1>                       "collect" : 42945,
  1>                       "collect_count" : 4
  1>                     }
  1>                   }
  1>                 ]

Superclass variables are protected, it's possible they are not reset between the collections.

@dbwiddis
Copy link
Member

Reproduced on current main branch on run 802

REPRODUCE WITH: ./gradlew ':rest-api-spec:yamlRestTest' --tests "org.opensearch.test.rest.ClientYamlTestSuiteIT" -Dtests.method="test {p0=search.aggregation/20_terms/string profiler via global ordinals}" -Dtests.seed=CBAA2A439F22709A -Dtests.security.manager=true -Dtests.jvm.argline="-XX:TieredStopAtLevel=1 -XX:ReservedCodeCacheSize=64m" -Dtests.locale=es-PR -Dtests.timezone=Pacific/Galapagos -Druntime.java=19

org.opensearch.test.rest.ClientYamlTestSuiteIT > test {p0=search.aggregation/20_terms/string profiler via global ordinals} FAILED
    java.lang.AssertionError: Failure at [search.aggregation/20_terms:857]: profile.shards.0.aggregations.0.debug.segments_with_multi_valued_ords didn't match expected value:
    profile.shards.0.aggregations.0.debug.segments_with_multi_valued_ords: expected Integer [0] but was Integer [1]
        at __randomizedtesting.SeedInfo.seed([CBAA2A439F22709A:43FE159931DE1D62]:0)
        at org.opensearch.test.rest.yaml.OpenSearchClientYamlSuiteTestCase.executeSection(OpenSearchClientYamlSuiteTestCase.java:459)
        at org.opensearch.test.rest.yaml.OpenSearchClientYamlSuiteTestCase.test(OpenSearchClientYamlSuiteTestCase.java:432)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
        at java.base/java.lang.reflect.Method.invoke(Method.java:578)
        at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at org.junit.rules.RunRules.evaluate(RunRules.java:20)
        at org.apache.lucene.tests.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:48)
        at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
        at org.apache.lucene.tests.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:45)
        at org.apache.lucene.tests.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
        at org.apache.lucene.tests.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:44)
        at org.junit.rules.RunRules.evaluate(RunRules.java:20)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
        at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
        at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at org.apache.lucene.tests.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:38)
        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at org.apache.lucene.tests.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
        at org.apache.lucene.tests.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:44)
        at org.apache.lucene.tests.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
        at org.apache.lucene.tests.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:47)
        at org.junit.rules.RunRules.evaluate(RunRules.java:20)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.base/java.lang.Thread.run(Thread.java:1589)

        Caused by:
        java.lang.AssertionError: profile.shards.0.aggregations.0.debug.segments_with_multi_valued_ords didn't match expected value:
        profile.shards.0.aggregations.0.debug.segments_with_multi_valued_ords: expected Integer [0] but was Integer [1]
            at org.opensearch.test.rest.yaml.section.MatchAssertion.doAssert(MatchAssertion.java:115)
            at org.opensearch.test.rest.yaml.section.Assertion.execute(Assertion.java:89)
            at org.opensearch.test.rest.yaml.OpenSearchClientYamlSuiteTestCase.executeSection(OpenSearchClientYamlSuiteTestCase.java:448)
            ... 39 more


Suite: Test class org.opensearch.test.rest.ClientYamlTestSuiteIT
  1> [2022-12-27T20:22:46,528][INFO ][o.o.t.r.ClientYamlTestSuiteIT] [test] [p0=search.aggregation/20_terms/string profiler via global ordinals] before test
  1> [2022-12-27T20:22:46,624][INFO ][o.o.t.r.ClientYamlTestSuiteIT] [test] initializing REST clients against [http://[::1]:59346, http://127.0.0.1:59347]
  2> SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
  2> SLF4J: Defaulting to no-operation (NOP) logger implementation
  2> SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
  1> [2022-12-27T20:22:47,174][INFO ][o.o.t.r.ClientYamlTestSuiteIT] [test] initializing client, minimum OpenSearch version [3.0.0], cluster-manager version, [3.0.0], hosts [http://[::1]:59346, http://127.0.0.1:59347]
  1> [2022-12-27T20:22:50,013][INFO ][o.o.t.r.ClientYamlTestSuiteIT] [test] Stash dump on test failure [{
  1>   "stash" : {
  1>     "body" : {
  1>       "took" : 78,
  1>       "timed_out" : false,
  1>       "_shards" : {
  1>         "total" : 1,
  1>         "successful" : 1,
  1>         "skipped" : 0,
  1>         "failed" : 0
  1>       },
  1>       "hits" : {
  1>         "total" : {
  1>           "value" : 4,
  1>           "relation" : "eq"
  1>         },
  1>         "max_score" : null,
  1>         "hits" : [ ]
  1>       },
  1>       "aggregations" : {
  1>         "str_terms" : {
  1>           "doc_count_error_upper_bound" : 0,
  1>           "sum_other_doc_count" : 0,
  1>           "buckets" : [
  1>             {
  1>               "key" : "sheep",
  1>               "doc_count" : 2,
  1>               "max_number" : {
  1>                 "value" : 3.0
  1>               }
  1>             },
  1>             {
  1>               "key" : "cow",
  1>               "doc_count" : 1,
  1>               "max_number" : {
  1>                 "value" : 1.0
  1>               }
  1>             },
  1>             {
  1>               "key" : "pig",
  1>               "doc_count" : 1,
  1>               "max_number" : {
  1>                 "value" : 1.0
  1>               }
  1>             }
  1>           ]
  1>         }
  1>       },
  1>       "profile" : {
  1>         "shards" : [
  1>           {
  1>             "id" : "[Ybx2LvxCStGEJigkrp22-g][test_1][0]",
  1>             "inbound_network_time_in_millis" : 0,
  1>             "outbound_network_time_in_millis" : 0,
  1>             "searches" : [
  1>               {
  1>                 "query" : [
  1>                   {
  1>                     "type" : "ConstantScoreQuery",
  1>                     "description" : "ConstantScore(*:*)",
  1>                     "time_in_nanos" : 1193430,
  1>                     "breakdown" : {
  1>                       "set_min_competitive_score_count" : 0,
  1>                       "match_count" : 0,
  1>                       "shallow_advance_count" : 0,
  1>                       "set_min_competitive_score" : 0,
  1>                       "next_doc" : 3783,
  1>                       "match" : 0,
  1>                       "next_doc_count" : 4,
  1>                       "score_count" : 0,
  1>                       "compute_max_score_count" : 0,
  1>                       "compute_max_score" : 0,
  1>                       "advance" : 2906,
  1>                       "advance_count" : 2,
  1>                       "score" : 0,
  1>                       "build_scorer_count" : 4,
  1>                       "create_weight" : 322124,
  1>                       "shallow_advance" : 0,
  1>                       "create_weight_count" : 1,
  1>                       "build_scorer" : 864617
  1>                     },
  1>                     "children" : [
  1>                       {
  1>                         "type" : "MatchAllDocsQuery",
  1>                         "description" : "*:*",
  1>                         "time_in_nanos" : 520758,
  1>                         "breakdown" : {
  1>                           "set_min_competitive_score_count" : 0,
  1>                           "match_count" : 0,
  1>                           "shallow_advance_count" : 0,
  1>                           "set_min_competitive_score" : 0,
  1>                           "next_doc" : 1629,
  1>                           "match" : 0,
  1>                           "next_doc_count" : 4,
  1>                           "score_count" : 0,
  1>                           "compute_max_score_count" : 0,
  1>                           "compute_max_score" : 0,
  1>                           "advance" : 1286,
  1>                           "advance_count" : 2,
  1>                           "score" : 0,
  1>                           "build_scorer_count" : 4,
  1>                           "create_weight" : 143490,
  1>                           "shallow_advance" : 0,
  1>                           "create_weight_count" : 1,
  1>                           "build_scorer" : 374353
  1>                         }
  1>                       }
  1>                     ]
  1>                   }
  1>                 ],
  1>                 "rewrite_time" : 13032,
  1>                 "collector" : [
  1>                   {
  1>                     "name" : "MultiCollector",
  1>                     "reason" : "search_multi",
  1>                     "time_in_nanos" : 1093521,
  1>                     "children" : [
  1>                       {
  1>                         "name" : "EarlyTerminatingCollector",
  1>                         "reason" : "search_count",
  1>                         "time_in_nanos" : 34156
  1>                       },
  1>                       {
  1>                         "name" : "ProfilingAggregator: [str_terms]",
  1>                         "reason" : "aggregation",
  1>                         "time_in_nanos" : 828680
  1>                       }
  1>                     ]
  1>                   }
  1>                 ]
  1>               }
  1>             ],
  1>             "aggregations" : [
  1>               {
  1>                 "type" : "GlobalOrdinalsStringTermsAggregator",
  1>                 "description" : "str_terms",
  1>                 "time_in_nanos" : 5756086,
  1>                 "breakdown" : {
  1>                   "reduce" : 0,
  1>                   "post_collection_count" : 1,
  1>                   "build_leaf_collector" : 733636,
  1>                   "build_aggregation" : 4344240,
  1>                   "build_aggregation_count" : 1,
  1>                   "build_leaf_collector_count" : 2,
  1>                   "post_collection" : 28194,
  1>                   "initialize" : 579825,
  1>                   "initialize_count" : 1,
  1>                   "reduce_count" : 0,
  1>                   "collect" : 70191,
  1>                   "collect_count" : 4
  1>                 },
  1>                 "debug" : {
  1>                   "segments_with_multi_valued_ords" : 1,
  1>                   "collection_strategy" : "dense",
  1>                   "segments_with_single_valued_ords" : 1,
  1>                   "deferred_aggregators" : [
  1>                     "max_number"
  1>                   ],
  1>                   "result_strategy" : "terms",
  1>                   "has_filter" : false
  1>                 },
  1>                 "children" : [
  1>                   {
  1>                     "type" : "MaxAggregator",
  1>                     "description" : "max_number",
  1>                     "time_in_nanos" : 1716904,
  1>                     "breakdown" : {
  1>                       "reduce" : 0,
  1>                       "post_collection_count" : 1,
  1>                       "build_leaf_collector" : 1633967,
  1>                       "build_aggregation" : 32496,
  1>                       "build_aggregation_count" : 1,
  1>                       "build_leaf_collector_count" : 2,
  1>                       "post_collection" : 774,
  1>                       "initialize" : 2970,
  1>                       "initialize_count" : 1,
  1>                       "reduce_count" : 0,
  1>                       "collect" : 46697,
  1>                       "collect_count" : 4
  1>                     }
  1>                   }
  1>                 ]
  1>               }
  1>             ]
  1>           }
  1>         ]
  1>       }
  1>     }
  1>   }
  1> }]

@dbwiddis
Copy link
Member

This same symptom appears to have been reported in #2176 with a fix in #2226 which added the force merge.

However, the ability to reproduce the bug on main even with force merge indicates that wasn't a complete fix.

This issue was closed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working flaky-test Random test failure that succeeds on second run
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants