elastic / elasticsearch

Free and Open Source, Distributed, RESTful Search Engine
https://www.elastic.co/products/elasticsearch
Other
993 stars 24.82k forks source link

[CI] RangeFieldTypeTests testRangeQueryIntersectsAdjacentValues failing #86284

Closed pgomulka closed 12 hours ago

pgomulka commented 2 years ago

Build scan: https://gradle-enterprise.elastic.co/s/2vshbqrk26hss/tests/:server:test/org.elasticsearch.index.mapper.RangeFieldTypeTests/testRangeQueryIntersectsAdjacentValues

Reproduction line: ./gradlew ':server:test' --tests "org.elasticsearch.index.mapper.RangeFieldTypeTests.testRangeQueryIntersectsAdjacentValues" -Dtests.seed=9F5B6EA0226718D0 -Dtests.locale=en-CA -Dtests.timezone=America/Port-au-Prince -Druntime.java=17

Applicable branches: 8.2

Reproduces locally?: Yes

Failure history: https://gradle-enterprise.elastic.co/scans/tests?tests.container=org.elasticsearch.index.mapper.RangeFieldTypeTests&tests.test=testRangeQueryIntersectsAdjacentValues

Failure excerpt:

java.lang.IllegalArgumentException: Range query `from` value (186414999) is greater than `to` value (186414001)

  at __randomizedtesting.SeedInfo.seed([9F5B6EA0226718D0:9E8E03A0959B9218]:0)
  at org.elasticsearch.index.mapper.RangeType.createQuery(RangeType.java:782)
  at org.elasticsearch.index.mapper.RangeType$6.intersectsQuery(RangeType.java:733)
  at org.elasticsearch.index.mapper.RangeType$2.intersectsQuery(RangeType.java:323)
  at org.elasticsearch.index.mapper.RangeType.createRangeQuery(RangeType.java:894)
  at org.elasticsearch.index.mapper.RangeType$2.rangeQuery(RangeType.java:308)
  at org.elasticsearch.index.mapper.RangeFieldMapper$RangeFieldType.rangeQuery(RangeFieldMapper.java:315)
  at org.elasticsearch.index.mapper.RangeFieldTypeTests.testRangeQueryIntersectsAdjacentValues(RangeFieldTypeTests.java:136)
  at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-2)
  at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
  at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.lang.reflect.Method.invoke(Method.java:568)
  at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1758)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:946)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:982)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:996)
  at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at org.apache.lucene.tests.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:44)
  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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:375)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:824)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:475)
  at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:955)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:840)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:891)
  at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:902)
  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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:375)
  at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:831)
  at java.lang.Thread.run(Thread.java:833)
elasticmachine commented 2 years ago

Pinging @elastic/es-search (Team:Search)

pgomulka commented 2 years ago

the tests uses from = {ZonedDateTime@5468} "1970-01-03T03:46:54Z" to = {ZonedDateTime@5469} "1970-01-03T03:46:54.001Z"

it rounds up from -> 1970-01-03T03:46:54.999999999Z - and I think this might be a bug. If we used "1970-01-03T03:46:54.000Z" it would be fine.

and it rounds to -> 1970-01-03T03:46:54.001Z

it converts this to epoch: low = {Long@7027} 186414999 high = {Long@7028} 186414001

and low > high which causes an exception

elasticmachine commented 2 years ago

Pinging @elastic/es-core-infra (Team:Core/Infra)

cbuescher commented 2 years ago

I think #86508 is caused by the same problem as this test failure, although its happening in "testFromLargerToErrors". The failures can be reproduced by picking the "DATE" field test type and provoking a "from" value that is 1ms into the next second, e.g. by modifying the test like so:

--- a/server/src/test/java/org/elasticsearch/index/mapper/RangeFieldTypeTests.java
+++ b/server/src/test/java/org/elasticsearch/index/mapper/RangeFieldTypeTests.java
@@ -54,7 +54,7 @@ public class RangeFieldTypeTests extends FieldTypeTestCase {

     @Before
     public void setupProperties() {
-        type = randomFrom(RangeType.values());
+        type = RangeType.DATE; //randomFrom(RangeType.values());
         nowInMillis = randomNonNegativeLong();
     }

@@ -155,7 +155,7 @@ public class RangeFieldTypeTests extends FieldTypeTestCase {
                 break;
             }
             case DATE: {
-                long fromValue = randomInt();
+                long fromValue = (Math.round(randomInt()/1000)*1000) + 1;
                 from = ZonedDateTime.ofInstant(Instant.ofEpochMilli(fromValue), ZoneOffset.UTC);
                 to = ZonedDateTime.ofInstant(Instant.ofEpochMilli(fromValue - 1), ZoneOffset.UTC);
                 break;

I think this is a genuine bug that might habe been introduced by some changed in date rounding on the 8.x line. The same setup still passes on 7.17 for me. The bug should show up rarely but probably also goes unnoticed in practice, since it only gets triggered by this relatively rare setup.

pugnascotia commented 2 years ago

Another failure:

https://gradle-enterprise.elastic.co/s/3axfhioqs3tdk

ywelsch commented 2 years ago

I'm removing the search label as this looks to be related to JavaDateMathParser's rounding, which is not owned by the search team.

albertzaharovits commented 1 year ago

Another one that reproduces: https://gradle-enterprise.elastic.co/s/xd75tndam7yrc

./gradlew ':server:test' --tests "org.elasticsearch.index.mapper.RangeFieldTypeTests.testFromLargerToErrors" -Dtests.seed=149B9A22D5DE2C10 -Dtests.locale=hi -Dtests.timezone=Europe/Saratov -Druntime.java=17 -Dtests.fips.enabled=true

Going to mute

benwtrent commented 1 year ago

This issue occurred again.

./gradlew ':server:test' --tests "org.elasticsearch.index.mapper.RangeFieldTypeTests.testRangeQueryIntersectsAdjacentValues" -Dtests.seed=1B8724C3D83D4334 -Dtests.locale=ru -Dtests.timezone=Canada/Central -Druntime.java=20

Note, the parameters are:

The cause is the date field parsing for the instant. It is losing some accuracy even though the instances are correctly 1 second apart (and in the correct order...)

Gonna mute testRangeQueryIntersectsAdjacentValues as it was forgotten for some reason.

lkts commented 5 months ago

I noticed those mutes while doing other work and took a look (specifically at testRangeQueryIntersectsAdjacentValues).

This happens because of the usage of roundupParser which is enabled here https://github.com/elastic/elasticsearch/blob/a7119a38674d32d5acc2e746d72b922b93802f3a/server/src/main/java/org/elasticsearch/index/mapper/RangeType.java#L288

The problem is that roundupParser does not work on millisecond level, it will round up the entire second by setting nanos to 999_999_999. This is different from the logic of parsing/storing bounds where we store epoch milliseconds and therefore adjust bounds by a millisecond in a gt case to produce a gte. Test testRangeQueryIntersectsAdjacentValues seems to be aware of that and rightfully expects bounds that are 1 millisecond apart to work.

The rounding logic was introduced in #50237 which points to documentation saying that gt "Rounds up to the first millisecond not covered by the rounded date.". The last statement describes exactly what we need but it does not seem to be true even though it is documented. Presumably it was broken all the way in #37604?

So to me it does seem like there is something going on with date time parsing here.

elasticsearchmachine commented 12 hours ago

This issue has been closed because it has been open for too long with no activity.

Any muted tests that were associated with this issue have been unmuted.

If the tests begin failing again, a new issue will be opened, and they may be muted again.