[
https://issues.apache.org/jira/browse/SOLR-15555?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17415654#comment-17415654
]
Chris M. Hostetter commented on SOLR-15555:
-------------------------------------------
Here's the patch i've currently got applied locally to try and force more
churn...
{code:java}
diff --git a/solr/core/src/test/org/apache/solr/search/TestRangeQuery.java
b/solr/core/src/test/org/apache/solr/search/TestRangeQuery.java
index fc2689f7f42..2b623da93ff 100644
--- a/solr/core/src/test/org/apache/solr/search/TestRangeQuery.java
+++ b/solr/core/src/test/org/apache/solr/search/TestRangeQuery.java
@@ -374,8 +374,9 @@ public class TestRangeQuery extends SolrTestCaseJ4 {
}
@Test
+ @org.apache.solr.util.LogLevel("org.apache.solr.util.TestInjection=DEBUG")
public void testRangeQueryWithFilterCache() throws Exception {
- TestInjection.delayBeforeCreatingNewDocSet = 500;
+ TestInjection.delayBeforeCreatingNewDocSet = 50;
// sometimes a very small index, sometimes a very large index
// final int numDocs = random().nextBoolean() ? random().nextInt(50) :
atLeast(1000);
@@ -384,17 +385,18 @@ public class TestRangeQuery extends SolrTestCaseJ4 {
addInt(doc, 0, 0, "foo_i");
});
- ExecutorService queryService = ExecutorUtil.newMDCAwareFixedThreadPool(4,
new SolrNamedThreadFactory("TestRangeQuery"));
+ for (int j = 1; j < 222; j++) {
+ ExecutorService queryService = ExecutorUtil.newMDCAwareFixedThreadPool(5,
new SolrNamedThreadFactory("TestRangeQuery-" + j));
try (SolrCore core = h.getCoreInc()) {
SolrRequestHandler defaultHandler = core.getRequestHandler("");
ModifiableSolrParams params = new ModifiableSolrParams();
params.set("q", "*:*");
- params.add("fq", "id:[0 TO 222]"); // These should all come from
FilterCache
+ params.add("fq", "id:[0 TO "+j+"]"); // These should all come from
FilterCache
// 10 threads with 4 executors would be enough for 3 waves, or
approximately 1500ms of delay
- CountDownLatch atLeastOnceCompleted = new CountDownLatch(1);
- for (int i = 0; i < 10; i++) {
+ CountDownLatch atLeastOnceCompleted = new CountDownLatch(30);
+ for (int i = 0; i < 100; i++) {
queryService.submit(() -> {
try (SolrQueryRequest req = req(params)) {
core.execute(defaultHandler, req, new SolrQueryResponse());
@@ -405,10 +407,12 @@ public class TestRangeQuery extends SolrTestCaseJ4 {
queryService.shutdown(); // No more requests will be queued up
atLeastOnceCompleted.await(); // Wait for the first query to complete
- assertTrue(queryService.awaitTermination(1, TimeUnit.SECONDS)); // All
queries after should be very fast
+ assertTrue(queryService.awaitTermination(5, TimeUnit.SECONDS)); // All
queries after should be very fast
assertEquals("Create only one DocSet outside of cache", 1,
TestInjection.countDocSetDelays.get());
}
+ TestInjection.countDocSetDelays.set(0);
+ }
}
@Test
{code}
Beasting with that patch applied has uncovered at least one source of problems
iwth the test: auto-warming may kick in (not sure why?) during the index
creation - so I think we're seeing DocSet creationg for _different_ caches (for
different searchers?) ...
{code}
hossman@slate:~/lucene/solr [j11] [*main] $ ./gradlew -p solr/core beast
-Ptests.dups=100 -Ptests.iters=5 --tests
TestRangeQuery.testRangeQueryWithFilterCache
{code}
{noformat}
2> 17723 INFO
(TEST-TestRangeQuery.testRangeQueryWithFilterCache-seed#[BD9DED4AEC58B38]) [
x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null
path=null params={}{add=[98 (1710986094582956032)]} 0 0
2> 17733 INFO (searcherExecutor-13-thread-1-processing-x:collection1) [
x:collection1 ] o.a.s.u.TestInjection Pausing DocSet for 50ms
2> 17733 DEBUG (searcherExecutor-13-thread-1-processing-x:collection1) [
x:collection1 ] o.a.s.u.TestInjection
2> => java.lang.Exception: Stack Trace
2> at
org.apache.solr.util.TestInjection.injectDocSetDelay(TestInjection.java:591)
2> java.lang.Exception: Stack Trace
2> at
org.apache.solr.util.TestInjection.injectDocSetDelay(TestInjection.java:591)
[main/:9.0.0-SNAPSHOT b60642c719f73f998d5130837b0fbaa1b91687a7 [snapshot build,
details omitted]]
2> at
org.apache.solr.query.SolrRangeQuery.createDocSet(SolrRangeQuery.java:171)
[main/:?]
2> at
org.apache.solr.query.SolrRangeQuery.createDocSet(SolrRangeQuery.java:167)
[main/:?]
2> at org.apache.solr.search.DocSetUtil.createDocSet(DocSetUtil.java:129)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getDocSetNC(SolrIndexSearcher.java:1173)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.lambda$getAndCacheDocSet$1(SolrIndexSearcher.java:854)
[main/:?]
2> at
org.apache.solr.search.CaffeineCache.computeAsync(CaffeineCache.java:229)
[main/:?]
2> at
org.apache.solr.search.CaffeineCache.computeIfAbsent(CaffeineCache.java:244)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getAndCacheDocSet(SolrIndexSearcher.java:854)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getDocSet(SolrIndexSearcher.java:1217)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getDocSet(SolrIndexSearcher.java:1185)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.cacheDocSet(SolrIndexSearcher.java:781)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher$2.regenerateItem(SolrIndexSearcher.java:564)
[main/:?]
2> at org.apache.solr.search.CaffeineCache.warm(CaffeineCache.java:393)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.warm(SolrIndexSearcher.java:2170)
[main/:?]
2> at
org.apache.solr.core.SolrCore.lambda$getSearcher$16(SolrCore.java:2363)
[main/:?]
2> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:235)
[solr-solrj-9.0.0-SNAPSHOT.jar:9.0.0-SNAPSHOT
b60642c719f73f998d5130837b0fbaa1b91687a7 [snapshot build, details omitted]]
2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[?:?]
2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[?:?]
2> at java.lang.Thread.run(Thread.java:834) [?:?]
2> 17784 INFO (searcherExecutor-13-thread-1-processing-x:collection1) [
x:collection1 ] o.a.s.u.TestInjection Pausing DocSet for 50ms
2> 17784 DEBUG (searcherExecutor-13-thread-1-processing-x:collection1) [
x:collection1 ] o.a.s.u.TestInjection
2> => java.lang.Exception: Stack Trace
2> at
org.apache.solr.util.TestInjection.injectDocSetDelay(TestInjection.java:591)
2> java.lang.Exception: Stack Trace
2> at
org.apache.solr.util.TestInjection.injectDocSetDelay(TestInjection.java:591)
[main/:9.0.0-SNAPSHOT b60642c719f73f998d5130837b0fbaa1b91687a7 [snapshot build,
details omitted]]
2> at
org.apache.solr.query.SolrRangeQuery.createDocSet(SolrRangeQuery.java:171)
[main/:?]
2> at
org.apache.solr.query.SolrRangeQuery.createDocSet(SolrRangeQuery.java:167)
[main/:?]
2> at org.apache.solr.search.DocSetUtil.createDocSet(DocSetUtil.java:129)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getDocSetNC(SolrIndexSearcher.java:1173)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.lambda$getAndCacheDocSet$1(SolrIndexSearcher.java:854)
[main/:?]
2> at
org.apache.solr.search.CaffeineCache.computeAsync(CaffeineCache.java:229)
[main/:?]
2> at
org.apache.solr.search.CaffeineCache.computeIfAbsent(CaffeineCache.java:244)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getAndCacheDocSet(SolrIndexSearcher.java:854)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getDocSet(SolrIndexSearcher.java:1217)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getDocSet(SolrIndexSearcher.java:1185)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.cacheDocSet(SolrIndexSearcher.java:781)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher$2.regenerateItem(SolrIndexSearcher.java:564)
[main/:?]
2> at org.apache.solr.search.CaffeineCache.warm(CaffeineCache.java:393)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.warm(SolrIndexSearcher.java:2170)
[main/:?]
2> at
org.apache.solr.core.SolrCore.lambda$getSearcher$16(SolrCore.java:2363)
[main/:?]
2> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:235)
[solr-solrj-9.0.0-SNAPSHOT.jar:9.0.0-SNAPSHOT
b60642c719f73f998d5130837b0fbaa1b91687a7 [snapshot build, details omitted]]
2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[?:?]
2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[?:?]
2> at java.lang.Thread.run(Thread.java:834) [?:?]
2> 17842 INFO (searcherExecutor-13-thread-1-processing-x:collection1) [
x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher
autowarm time: 102 ms
2> 17844 INFO
(TEST-TestRangeQuery.testRangeQueryWithFilterCache-seed#[BD9DED4AEC58B38]) [
x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null
path=null params={}{commit=} 0 120
2> 17846 INFO (TestRangeQuery-1-239-thread-1-processing-x:collection1) [
] o.a.s.u.TestInjection Pausing DocSet for 50ms
2> 17846 DEBUG (TestRangeQuery-1-239-thread-1-processing-x:collection1) [
] o.a.s.u.TestInjection
2> => java.lang.Exception: Stack Trace
2> at
org.apache.solr.util.TestInjection.injectDocSetDelay(TestInjection.java:591)
2> java.lang.Exception: Stack Trace
2> at
org.apache.solr.util.TestInjection.injectDocSetDelay(TestInjection.java:591)
[main/:9.0.0-SNAPSHOT b60642c719f73f998d5130837b0fbaa1b91687a7 [snapshot build,
details omitted]]
2> at
org.apache.solr.query.SolrRangeQuery.createDocSet(SolrRangeQuery.java:171)
[main/:?]
2> at
org.apache.solr.query.SolrRangeQuery.createDocSet(SolrRangeQuery.java:167)
[main/:?]
2> at org.apache.solr.search.DocSetUtil.createDocSet(DocSetUtil.java:129)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getDocSetNC(SolrIndexSearcher.java:1173)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.lambda$getAndCacheDocSet$1(SolrIndexSearcher.java:854)
[main/:?]
2> at
org.apache.solr.search.CaffeineCache.computeAsync(CaffeineCache.java:229)
[main/:?]
2> at
org.apache.solr.search.CaffeineCache.computeIfAbsent(CaffeineCache.java:244)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getAndCacheDocSet(SolrIndexSearcher.java:854)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getPositiveDocSet(SolrIndexSearcher.java:822)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getProcessedFilter(SolrIndexSearcher.java:1009)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getDocListNC(SolrIndexSearcher.java:1542)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.getDocListC(SolrIndexSearcher.java:1424)
[main/:?]
2> at
org.apache.solr.search.SolrIndexSearcher.search(SolrIndexSearcher.java:608)
[main/:?]
2> at
org.apache.solr.handler.component.QueryComponent.doProcessUngroupedSearch(QueryComponent.java:1545)
[main/:?]
2> at
org.apache.solr.handler.component.QueryComponent.process(QueryComponent.java:420)
[main/:?]
2> at
org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:367)
[main/:?]
2> at
org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:212)
[main/:?]
2> at org.apache.solr.core.SolrCore.execute(SolrCore.java:2617) [main/:?]
2> at
org.apache.solr.search.TestRangeQuery.lambda$testRangeQueryWithFilterCache$2(TestRangeQuery.java:402)
[test/:?]
2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
2> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:235)
[solr-solrj-9.0.0-SNAPSHOT.jar:9.0.0-SNAPSHOT
b60642c719f73f998d5130837b0fbaa1b91687a7 [snapshot build, details omitted]]
2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[?:?]
2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[?:?]
2> at java.lang.Thread.run(Thread.java:834) [?:?]
2> 17899 INFO (TestRangeQuery-1-239-thread-1-processing-x:collection1) [
] o.a.s.c.S.Request [collection1] webapp=null path=null
params={q=*:*&fq=id:[0+TO+1]} hits=2 status=0 QTime=53
2> 17899 INFO (TestRangeQuery-1-239-thread-5-processing-x:collection1) [
] o.a.s.c.S.Request [collection1] webapp=null path=null
params={q=*:*&fq=id:[0+TO+1]} hits=2 status=0 QTime=52
2> 17899 INFO (TestRangeQuery-1-239-thread-2-processing-x:collection1) [
] o.a.s.c.S.Request [collection1] webapp=null path=null
params={q=*:*&fq=id:[0+TO+1]} hits=2 status=0 QTime=53
2> 17900 INFO (TestRangeQuery-1-239-thread-2-processing-x:collection1) [
] o.a.s.c.S.Request [collection1] webapp=null path=null
params={q=*:*&fq=id:[0+TO+1]} hits=2 status=0 QTime=0
2> 17900 INFO (TestRangeQuery-1-239-thread-2-processing-x:collection1) [
] o.a.s.c.S.Request [collection1] webapp=null path=null
params={q=*:*&fq=id:[0+TO+1]} hits=2 status=0 QTime=0
...
2> 17908 INFO
(TEST-TestRangeQuery.testRangeQueryWithFilterCache-seed#[BD9DED4AEC58B38]) [
] o.a.s.SolrTestCaseJ4 ###Ending testRangeQueryWithFilterCache
{seed=[BD9DED4AEC58B38:432DB667DFF77D55]}
> java.lang.AssertionError: Create only one DocSet outside of cache
expected:<1> but was:<3>
> at
__randomizedtesting.SeedInfo.seed([BD9DED4AEC58B38:432DB667DFF77D55]:0)
> at org.junit.Assert.fail(Assert.java:89)
> at org.junit.Assert.failNotEquals(Assert.java:835)
> at org.junit.Assert.assertEquals(Assert.java:647)
> at
org.apache.solr.search.TestRangeQuery.testRangeQueryWithFilterCache(TestRangeQuery.java:412)
> at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
> at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
> at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
> at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
> at org.junit.rules.RunRules.evaluate(RunRules.java:20)
> at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:44)
> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
> at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:45)
> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
> at
org.apache.lucene.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:370)
> at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
> at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
> at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
> at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
> at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
> at org.junit.rules.RunRules.evaluate(RunRules.java:20)
> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at
org.apache.lucene.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.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:44)
> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:60)
> at
org.apache.lucene.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:370)
> at
com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
> at java.base/java.lang.Thread.run(Thread.java:834)
2> NOTE: reproduce with: gradlew test --tests
TestRangeQuery.testRangeQueryWithFilterCache -Dtests.seed=BD9DED4AEC58B38
-Dtests.slow=true -Dtests.badapples=true -Dtests.locale=yo-BJ
-Dtests.timezone=Pacific/Port_Moresby -Dtests.asserts=true
-Dtests.file.encoding=UTF-8
{noformat}
> Use filterCache.computeIfAbsent in SolrIndexSearcher
> ----------------------------------------------------
>
> Key: SOLR-15555
> URL: https://issues.apache.org/jira/browse/SOLR-15555
> Project: Solr
> Issue Type: Improvement
> Security Level: Public(Default Security Level. Issues are Public)
> Reporter: Mike Drob
> Assignee: Mike Drob
> Priority: Major
> Fix For: main (9.0), 8.10
>
> Time Spent: 5.5h
> Remaining Estimate: 0h
>
> When multiple concurrent queries come in at the same time, in several cases
> they can trigger concurrent computations of a DocSet for the cache. We should
> investigate where this happens and possibly take care to only do a single
> computation when possible.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
