elastic / elasticsearch

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

[CI] GeoIpDownloaderCliIT.testInvalidTimestamp failure #75221

Closed dimitris-athanasiou closed 1 week ago

dimitris-athanasiou commented 3 years ago

Build scan: https://gradle-enterprise.elastic.co/s/sotnvdenrgysw

Repro line: ./gradlew ':modules:ingest-geoip:internalClusterTest' --tests "org.elasticsearch.ingest.geoip.GeoIpDownloaderCliIT.testInvalidTimestamp" -Dtests.seed=9DC568B1B022BF2 -Dtests.locale=sr -Dtests.timezone=Asia/Seoul -Druntime.java=11

Reproduces locally?: No

Applicable branches: master

Failure history: Failed a few times in the past month, see here&_a=(columns:!(_source),index:b646ed00-7efc-11e8-bf69-63c8ef516157,interval:auto,query:(language:lucene,query:GeoIpDownloaderCliIT),sort:!(process.time-start,desc)))

Failure excerpt:

java.lang.AssertionError:   
Expected: not a collection containing "GeoLite2-ASN.mmdb"   
     but: was <[GeoLite2-ASN.mmdb_LICENSE.txt, GeoLite2-Country.mmdb, GeoLite2-ASN.mmdb_README.txt, GeoLite2-ASN.mmdb_COPYRIGHT.txt, GeoLite2-ASN.mmdb, GeoLite2-City.mmdb]>    
at __randomizedtesting.SeedInfo.seed([9DC568B1B022BF2:12C6D17C9532BB4]:0)   
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:18) 
at org.junit.Assert.assertThat(Assert.java:956) 
at org.junit.Assert.assertThat(Assert.java:923) 
at org.elasticsearch.ingest.geoip.GeoIpDownloaderIT.lambda$cleanUp$2(GeoIpDownloaderIT.java:109)    
at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:973)    
at org.elasticsearch.test.ESTestCase.assertBusy(ESTestCase.java:946)    
at org.elasticsearch.ingest.geoip.GeoIpDownloaderIT.cleanUp(GeoIpDownloaderIT.java:104) 
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) 
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)   
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)   
at java.lang.reflect.Method.invoke(Method.java:566) 
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1758)   
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:1004)  
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: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.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:375) 
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:831) 
at java.lang.Thread.run(Thread.java:834)
elasticmachine commented 3 years ago

Pinging @elastic/es-analytics-geo (Team:Analytics)

gwbrown commented 3 years ago

Another instance of this: https://gradle-enterprise.elastic.co/s/c2sdhoiwrf2fo

gwbrown commented 3 years ago

I'll also note that the repro line for this test does not actually run the test. Running the class from IntelliJ also does not actually run the test. Running ./gradlew :modules:ingest-geoip:check also does not run the test. I remain mystified as to how to actually run this test locally.

danhermann commented 3 years ago

This test failed again on master in https://gradle-enterprise.elastic.co/s/wzbkq4juyucvs

FWIW, I could not reproduce that one locally.

astefan commented 3 years ago

And another one: https://gradle-enterprise.elastic.co/s/apsspqdlx7jqm in 7.14

gwbrown commented 3 years ago

Another one, from a PR against 7.x: https://gradle-enterprise.elastic.co/s/qtxzi5x664h4s

probakowski commented 3 years ago

It fails frequently - I'm gonna mute it in https://github.com/elastic/elasticsearch/pull/75398 I wasn't able to reproduce it locally in few 1000s runs but CI seems to have no problems reproducing.

elasticmachine commented 3 years ago

Pinging @elastic/es-data-management (Team:Data Management)

martijnvg commented 3 years ago

I'm also unable to reproduce this locally. The teardown of this test class has also changed recently. I'm going to enable this test again with trace logging enabled for the geoip package.

martijnvg commented 3 years ago

The test has been enabled for some time now and hasn't failed. I will close this issue, if for some reason this test fails again then this issue can be re-opened or a new issue can be created.

andreidan commented 2 years ago

Another occurrence in 8.0 https://gradle-enterprise.elastic.co/s/4mua3tcr5q2c4

valeriy42 commented 2 years ago

Another occurrence in 8.1 https://gradle-enterprise.elastic.co/s/c4jzxbgt6slka

astefan commented 2 years ago

Another failure today on master: https://gradle-enterprise.elastic.co/s/exq2xfl2mgrmy

masseyke commented 1 year ago

This looks like #92888.

csoulios commented 1 year ago

Multiple failures again today:

All failures are on Windows instances and the following error is thrown for all .mmdb databases

[2023-02-23T08:24:58,912][INFO ][o.e.i.g.DatabaseReaderLazyLoader] [node_s1] evicted [0] entries from cache after reloading database [C:\Users\jenkins\workspace\platform-support\198\modules\ingest-geoip\build\testrun\internalClusterTest\temp\geoip-databases\7d--vNbhSe6TuwH5iuD2Wg\GeoLite2-Country.mmdb]
[2023-02-23T08:24:58,912][INFO ][o.e.i.g.DatabaseReaderLazyLoader] [node_s1] deleting [C:\Users\jenkins\workspace\platform-support\198\modules\ingest-geoip\build\testrun\internalClusterTest\temp\geoip-databases\7d--vNbhSe6TuwH5iuD2Wg\GeoLite2-Country.mmdb]
[2023-02-23T08:24:58,912][DEBUG][o.e.i.g.DatabaseNodeService] [node_s1] database [GeoLite2-ASN.mmdb] no longer exists, cleaning up...
[2023-02-23T08:24:58,912][INFO ][o.e.i.g.DatabaseReaderLazyLoader] [node_s1] evicted [0] entries from cache after reloading database [C:\Users\jenkins\workspace\platform-support\198\modules\ingest-geoip\build\testrun\internalClusterTest\temp\geoip-databases\7d--vNbhSe6TuwH5iuD2Wg\GeoLite2-ASN.mmdb]
[2023-02-23T08:24:58,912][INFO ][o.e.i.g.DatabaseReaderLazyLoader] [node_s1] deleting [C:\Users\jenkins\workspace\platform-support\198\modules\ingest-geoip\build\testrun\internalClusterTest\temp\geoip-databases\7d--vNbhSe6TuwH5iuD2Wg\GeoLite2-ASN.mmdb]
[2023-02-23T08:24:58,913][DEBUG][o.e.i.g.DatabaseNodeService] [node_s1] database [GeoLite2-City.mmdb] no longer exists, cleaning up...
[2023-02-23T08:24:58,913][INFO ][o.e.i.g.DatabaseReaderLazyLoader] [node_s1] evicted [0] entries from cache after reloading database [C:\Users\jenkins\workspace\platform-support\198\modules\ingest-geoip\build\testrun\internalClusterTest\temp\geoip-databases\7d--vNbhSe6TuwH5iuD2Wg\GeoLite2-City.mmdb]
[2023-02-23T08:24:58,913][INFO ][o.e.i.g.DatabaseReaderLazyLoader] [node_s1] deleting [C:\Users\jenkins\workspace\platform-support\198\modules\ingest-geoip\build\testrun\internalClusterTest\temp\geoip-databases\7d--vNbhSe6TuwH5iuD2Wg\GeoLite2-City.mmdb]
[2023-02-23T08:24:58,914][INFO ][o.e.i.g.DatabaseReaderLazyLoader] [node_s2] evicted [1] entries from cache after reloading database [C:\Users\jenkins\workspace\platform-support\198\modules\ingest-geoip\build\testrun\internalClusterTest\temp\geoip-databases\7ykYStW4R6GQZKa0xJ0YxQ\GeoLite2-Country.mmdb]
[2023-02-23T08:24:58,915][INFO ][o.e.i.g.DatabaseReaderLazyLoader] [node_s2] deleting [C:\Users\jenkins\workspace\platform-support\198\modules\ingest-geoip\build\testrun\internalClusterTest\temp\geoip-databases\7ykYStW4R6GQZKa0xJ0YxQ\GeoLite2-Country.mmdb]
[2023-02-23T08:24:58,916][ERROR][o.e.i.g.DatabaseNodeService] [node_s2] failed to clean database [GeoLite2-Country.mmdb]
java.nio.file.FileSystemException: C:\Users\jenkins\workspace\platform-support\198\modules\ingest-geoip\build\testrun\internalClusterTest\temp\geoip-databases\7ykYStW4R6GQZKa0xJ0YxQ\GeoLite2-Country.mmdb: The process cannot access the file because it is being used by another process
    at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:92) ~[?:?]
    at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:103) ~[?:?]
    at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:108) ~[?:?]
    at sun.nio.fs.WindowsFileSystemProvider.implDelete(WindowsFileSystemProvider.java:275) ~[?:?]
    at sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:105) ~[?:?]
    at org.apache.lucene.tests.mockfile.FilterFileSystemProvider.delete(FilterFileSystemProvider.java:134) ~[lucene-test-framework-9.4.2.jar:9.4.2 858d9b437047a577fa9457089afff43eefa461db - jpountz - 2022-11-17 12:56:39]
    at org.apache.lucene.tests.mockfile.FilterFileSystemProvider.delete(FilterFileSystemProvider.java:134) ~[lucene-test-framework-9.4.2.jar:9.4.2 858d9b437047a577fa9457089afff43eefa461db - jpountz - 2022-11-17 12:56:39]
    at org.apache.lucene.tests.mockfile.FilterFileSystemProvider.delete(FilterFileSystemProvider.java:134) ~[lucene-test-framework-9.4.2.jar:9.4.2 858d9b437047a577fa9457089afff43eefa461db - jpountz - 2022-11-17 12:56:39]
    at org.apache.lucene.tests.mockfile.FilterFileSystemProvider.delete(FilterFileSystemProvider.java:134) ~[lucene-test-framework-9.4.2.jar:9.4.2 858d9b437047a577fa9457089afff43eefa461db - jpountz - 2022-11-17 12:56:39]
    at java.nio.file.Files.delete(Files.java:1152) ~[?:?]
    at org.elasticsearch.ingest.geoip.DatabaseReaderLazyLoader.doClose(DatabaseReaderLazyLoader.java:235) ~[main/:?]
    at org.elasticsearch.ingest.geoip.DatabaseReaderLazyLoader.close(DatabaseReaderLazyLoader.java:224) ~[main/:?]
    at org.elasticsearch.ingest.geoip.DatabaseReaderLazyLoader.close(DatabaseReaderLazyLoader.java:218) ~[main/:?]
    at org.elasticsearch.ingest.geoip.DatabaseNodeService.removeStaleEntries(DatabaseNodeService.java:385) ~[main/:?]
    at org.elasticsearch.ingest.geoip.DatabaseNodeService.checkDatabases(DatabaseNodeService.java:258) ~[main/:?]
    at org.elasticsearch.ingest.geoip.DatabaseNodeService.lambda$initialize$0(DatabaseNodeService.java:161) ~[main/:?]
    at org.elasticsearch.cluster.service.ClusterApplierService.callClusterStateListener(ClusterApplierService.java:559) ~[elasticsearch-8.6.3-SNAPSHOT.jar:8.6.3-SNAPSHOT]
    at org.elasticsearch.cluster.service.ClusterApplierService.callClusterStateListeners(ClusterApplierService.java:545) ~[elasticsearch-8.6.3-SNAPSHOT.jar:8.6.3-SNAPSHOT]
    at org.elasticsearch.cluster.service.ClusterApplierService.applyChanges(ClusterApplierService.java:504) ~[elasticsearch-8.6.3-SNAPSHOT.jar:8.6.3-SNAPSHOT]
    at org.elasticsearch.cluster.service.ClusterApplierService.runTask(ClusterApplierService.java:428) ~[elasticsearch-8.6.3-SNAPSHOT.jar:8.6.3-SNAPSHOT]
    at org.elasticsearch.cluster.service.ClusterApplierService$UpdateTask.run(ClusterApplierService.java:154) ~[elasticsearch-8.6.3-SNAPSHOT.jar:8.6.3-SNAPSHOT]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:850) ~[elasticsearch-8.6.3-SNAPSHOT.jar:8.6.3-SNAPSHOT]
    at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.runAndClean(PrioritizedEsThreadPoolExecutor.java:257) ~[elasticsearch-8.6.3-SNAPSHOT.jar:8.6.3-SNAPSHOT]
    at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.run(PrioritizedEsThreadPoolExecutor.java:223) ~[elasticsearch-8.6.3-SNAPSHOT.jar:8.6.3-SNAPSHOT]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
    at java.lang.Thread.run(Thread.java:1589) ~[?:?]
kingherc commented 9 months ago

Another one at elasticsearch / periodic / platform-support / main / opensuse-leap-15 / platform-support-unix Test failures: GeoIpDownloaderIT » testInvalidTimestamp GeoIpDownloaderIT » testUseGeoIpProcessorWithDownloadedDBs

elasticsearchmachine commented 1 week 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.