I've been able to trigger this locally using `-Ptests.iters=20` (or
whatever). Still not sure what the issue is, but here's the request that's
triggering this for me:
2> 176445 INFO
(TEST-TestFiltering.testRandomFiltering-seed#[8C523D43388C3411]) []
o.a.s.c.S.Request webapp=null path=null
params={q=+-val_i:0+-val_i:2+-val_i:4+-val_i:5+-val_i:6+-val_i:8+-val_i:9+-val_i:15+-val_i:19+-val_i:24+-val_i:25+-val_i:26+-val_i:27+-val_i:28+-val_i:31+-val_i:33+-val_i:34+-val_i:38+-val_i:41+-val_i:42+-val_i:44+-val_i:45+-val_i:48+-val_i:50+-val_i:51+-val_i:52+-val_i:59+-val_i:60+-val_i:61+-val_i:62+-val_i:63+-val_i:64+-val_i:69+-val_i:70+-val_i:72+-val_i:74+-val_i:75+-val_i:78+-val_i:82+-val_i:83&fq={!+cache%3Dtrue+tag%3Dt}-_query_:"{!frange+v%3Dval_i+l%3D52+u%3D83}"&fq={!+cost%3D43}-_query_:"{!frange+v%3Dval_i+l%3D5+u%3D83}"&fq={!+tag%3Dt}id:RAND-190946395+OR+val_s:[00002+TO+00063]&fq={!cache%3Dfalse}+-val_i:1+-val_i:3+-val_i:4+-val_i:5+-val_i:7+-val_i:9+-val_i:12+-val_i:15+-val_i:19+-val_i:20+-val_i:21+-val_i:22+-val_i:24+-val_i:25+-val_i:27+-val_i:29+-val_i:30+-val_i:32+-val_i:34+-val_i:35+-val_i:36+-val_i:37+-val_i:39+-val_i:40+-val_i:42+-val_i:44+-val_i:45+-val_i:51+-val_i:52+-val_i:53+-val_i:57+-val_i:58+-val_i:63+-val_i:64+-val_i:70+-val_i:73+-val_i:75+-val_i:76+-val_i:81+-val_i:82+-val_i:83&wt=xml}
status=500 QTime=4
... and the specific query that's triggering (I added some logging):
`id:RAND-190946395 val_s:[00002 TO 00063]`
exact reproducing command:
gradlew :solr:core:test --tests TestFiltering.testRandomFiltering
-Dtests.seed=8C523D43388C3411 -Dtests.multiplier=3 -Dtests.locale=en-NU
-Dtests.timezone=America/Kentucky/Monticello -Dtests.asserts=true
-Dtests.file.encoding=UTF-8 -Ptests.iters=20 -Ptests.verbose=true 2>&1 |
gzip > /tmp/tests.log.gz
On Wed, Mar 15, 2023 at 12:01 PM Kevin Risden <kris...@apache.org> wrote:
> From first glance this reminded me of
> https://github.com/apache/solr/pull/1118 but doesn't look completely
> related.
>
> This section of code just seems questionable:
>
>
> https://github.com/apache/solr/blob/main/solr/core/src/java/org/apache/solr/search/CaffeineCache.java#L254
>
> We are doing a get inside a computeifabsent. I'd have to think about it
> more, but I wonder if there is something where we end up in a race
> condition here.
> Kevin Risden
>
>
>
> On Wed, Mar 15, 2023 at 10:04 AM Mikhail Khludnev <m...@apache.org> wrote:
>
> > Should we just set solr.filterCache.async=true?
> >
> > On Wed, Mar 15, 2023 at 4:57 PM Mikhail Khludnev <m...@apache.org>
> wrote:
> >
> > > Hi, devs.
> > > I see in my inbox it fails from time to time.
> > > It seems the cause is .. caffeine
> > >
> >
> https://jenkins.thetaphi.de/job/Solr-main-Linux/10777/testReport/junit/org.apache.solr.search/TestFiltering/testRandomFiltering/
> > >
> > > => java.lang.IllegalStateException: Recursive update
> > > at
> >
> java.base/java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1958)
> > > java.lang.IllegalStateException: Recursive update
> > > at
> >
> java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1958)
> > ~[?:?]
> > > at
> >
> com.github.benmanes.caffeine.cache.BoundedLocalCache.doComputeIfAbsent(BoundedLocalCache.java:2675)
> > ~[caffeine-3.1.5.jar:?]
> > > ..
> > > at
> >
> com.github.benmanes.caffeine.cache.LocalManualCache.get(LocalManualCache.java:62)
> > ~[caffeine-3.1.5.jar:?]
> > > at
> >
> org.apache.solr.search.CaffeineCache.computeIfAbsent(CaffeineCache.java:254)
> > ~[main/:?]
> > > at
> >
> org.apache.solr.search.SolrIndexSearcher.getAndCacheDocSet(SolrIndexSearcher.java:972)
> > ~[main/:?]
> > > ...
> > > at
> >
> org.apache.solr.search.SolrIndexSearcher.getDocListC(SolrIndexSearcher.java:1673)
> > ~[main/:?]
> > > at
> >
> org.apache.solr.search.SolrIndexSearcher.search(SolrIndexSearcher.java:712)
> > ~[main/:?]
> > >
> > > Isn't it something obvious requiring some config tweak? Can't
> (obviously)
> > > reproduce this seed locally. Btw, why it's recursive, can't see any
> > > reentrance in the call stack.
> > >
> > > On Wed, Mar 15, 2023 at 10:57 AM Policeman Jenkins Server <
> > > jenk...@thetaphi.de> wrote:
> > >
> > >> Build: https://jenkins.thetaphi.de/job/Solr-main-Linux/10777/
> > >> Java: 64bit/hotspot/jdk-16.0.2 -XX:+UseCompressedOops -XX:+UseSerialGC
> > >>
> > >> 1 tests failed.
> > >> FAILED: org.apache.solr.search.TestFiltering.testRandomFiltering
> > >>
> > >> Error Message:
> > >> java.lang.AssertionError: FAILURE: indexSize=97 iiter=1 qiter=257
> > >> request=[q, {!cache=false cost=17} val_i:0 val_i:1 val_i:2 val_i:8
> > val_i:11
> > >> val_i:12 val_i:14 val_i:16 val_i:17 val_i:20 val_i:21 val_i:22
> val_i:23
> > >> val_i:24 val_i:25 val_i:30 val_i:31 val_i:34 val_i:35 val_i:36
> val_i:41
> > >> val_i:43 val_i:45 val_i:48 val_i:50 val_i:51 val_i:53 val_i:60
> val_i:61
> > >> val_i:65 val_i:68 val_i:70 val_i:74 val_i:75 val_i:76 val_i:78
> val_i:79
> > >> val_i:80 val_i:82 val_i:84 val_i:85 val_i:87 val_i:89 val_i:92
> val_i:93
> > >> val_i:95 val_i:96, fq, val_s:{00004 TO 00100} AND val_s:[00005 TO
> > 00099],
> > >> fq, {!cache=false cost=42} val_i:0 val_i:1 val_i:2 val_i:4 val_i:5
> > val_i:6
> > >> val_i:8 val_i:10 val_i:11 val_i:13 val_i:15 val_i:19 val_i:20 val_i:24
> > >> val_i:26 val_i:27 val_i:28 val_i:29 val_i:30 val_i:31 val_i:32
> val_i:33
> > >> val_i:34 val_i:35 val_i:36 val_i:37 val_i:40 val_i:41 val_i:42
> val_i:44
> > >> val_i:47 val_i:48 val_i:49 val_i:51 val_i:55 val_i:56 val_i:58
> val_i:59
> > >> val_i:60 val_i:61 val_i:62 val_i:66 val_i:67 val_i:68 val_i:70
> val_i:71
> > >> val_i:72 val_i:74 val_i:75 val_i:76 val_i:77 val_i:79 val_i:81
> val_i:86
> > >> val_i:88 val_i:89 val_i:91 val_i:92 val_i:94, facet, true,
> facet.query,
> > >> *:*, facet.query, {!key=multiSelect ex=t}*:*, facet.query,
> > {!key=facetQuery
> > >> frange v=val_i l=89 u=97}]
> > >>
> > >> Stack Trace:
> > >> java.lang.AssertionError: FAILURE: indexSize=97 iiter=1 qiter=257
> > >> request=[q, {!cache=false cost=17} val_i:0 val_i:1 val_i:2 val_i:8
> > val_i:11
> > >> val_i:12 val_i:14 val_i:16 val_i:17 val_i:20 val_i:21 val_i:22
> val_i:23
> > >> val_i:24 val_i:25 val_i:30 val_i:31 val_i:34 val_i:35 val_i:36
> val_i:41
> > >> val_i:43 val_i:45 val_i:48 val_i:50 val_i:51 val_i:53 val_i:60
> val_i:61
> > >> val_i:65 val_i:68 val_i:70 val_i:74 val_i:75 val_i:76 val_i:78
> val_i:79
> > >> val_i:80 val_i:82 val_i:84 val_i:85 val_i:87 val_i:89 val_i:92
> val_i:93
> > >> val_i:95 val_i:96, fq, val_s:{00004 TO 00100} AND val_s:[00005 TO
> > 00099],
> > >> fq, {!cache=false cost=42} val_i:0 val_i:1 val_i:2 val_i:4 val_i:5
> > val_i:6
> > >> val_i:8 val_i:10 val_i:11 val_i:13 val_i:15 val_i:19 val_i:20 val_i:24
> > >> val_i:26 val_i:27 val_i:28 val_i:29 val_i:30 val_i:31 val_i:32
> val_i:33
> > >> val_i:34 val_i:35 val_i:36 val_i:37 val_i:40 val_i:41 val_i:42
> val_i:44
> > >> val_i:47 val_i:48 val_i:49 val_i:51 val_i:55 val_i:56 val_i:58
> val_i:59
> > >> val_i:60 val_i:61 val_i:62 val_i:66 val_i:67 val_i:68 val_i:70
> val_i:71
> > >> val_i:72 val_i:74 val_i:75 val_i:76 val_i:77 val_i:79 val_i:81
> val_i:86
> > >> val_i:88 val_i:89 val_i:91 val_i:92 val_i:94, facet, true,
> facet.query,
> > >> *:*, facet.query, {!key=multiSelect ex=t}*:*, facet.query,
> > {!key=facetQuery
> > >> frange v=val_i l=89 u=97}]
> > >> at
> > >>
> __randomizedtesting.SeedInfo.seed([8C523D43388C3411:93319E86DDAB7418]:0)
> > >> at org.junit.Assert.fail(Assert.java:89)
> > >> at
> > >>
> >
> org.apache.solr.search.TestFiltering.testRandomFiltering(TestFiltering.java:578)
> > >> at
> > >> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
> > >> Method)
> > >> at
> > >>
> >
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
> > >> at
> > >>
> >
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> > >> at java.base/java.lang.reflect.Method.invoke(Method.java:567)
> > >> 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.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:80)
> > >> at org.junit.rules.RunRules.evaluate(RunRules.java:20)
> > >> 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 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:390)
> > >> at
> > >>
> >
> com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:843)
> > >> at
> > >>
> >
> com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:490)
> > >> 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
> > >>
> >
> 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.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
> > >> at
> > >>
> >
> org.apache.lucene.tests.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:43)
> > >> at
> > >>
> >
> com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:80)
> > >> at org.junit.rules.RunRules.evaluate(RunRules.java:20)
> > >> 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:390)
> > >> at
> > >>
> >
> com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:850)
> > >> at java.base/java.lang.Thread.run(Thread.java:831)
> > >>
> > >> ---------------------------------------------------------------------
> > >> To unsubscribe, e-mail: builds-unsubscr...@solr.apache.org
> > >> For additional commands, e-mail: builds-h...@solr.apache.org
> > >
> > >
> > >
> > > --
> > > Sincerely yours
> > > Mikhail Khludnev
> > > https://t.me/MUST_SEARCH
> > > A caveat: Cyrillic!
> > >
> >
> >
> > --
> > Sincerely yours
> > Mikhail Khludnev
> > https://t.me/MUST_SEARCH
> > A caveat: Cyrillic!
> >
>
