Thanks for update, Michael.
I raised https://issues.apache.org/jira/browse/SOLR-16707.
On Fri, Mar 17, 2023 at 5:47 AM Michael Gibney <mich...@michaelgibney.net>
wrote:
> I think this is basically a BooleanQuery and/or SolrRangeQuery variant
> of SOLR-15762. BoolQParserPlugin wraps `Occur.FILTER` subclauses in
> `FilterQuery`, so you could definitely see recursive updates that way,
> and SolrRangeQuery (which I think is the culprit in this case)
> likewise consults the filterCache within query execution. I'm not sure
> there are any other queries that are similarly susceptible, but in any
> case I think we need to extend the accommodations made for JoinQuery
> in SOLR-15762 to cover these other queries. There's also some relevant
> discussion on SOLR-15555.
>
> I think the reason this doesn't _look_ recursive is that
> ConcurrentHashMap detects recursive updates _after_ they've happened,
> so by the time the condition is detected, the recursion is no longer
> reflected in the stack trace.
>
> IMO the ideal way forward would be to fully embrace async caches. Solr
> has recursive cache consultation built into some central features. Is
> there any good reason to leave async=false as a configuration option?
> If we leave it as an option, perhaps we could rewrite
> `computeIfAbsent` on `async=false` caches to internally call
> get-then-put (which is what SolrIndexSearcher used to do directly
> before SOLR-15555). The user would be no worse off than they were
> pre-SOLR-15555, and everything should "just work". That said, why
> would anyone actually _choose_ `async=false` ... but then that's where
> we already are, unless I'm missing something.
>
>
>
>
> On Wed, Mar 15, 2023 at 2:20 PM Michael Gibney
> <mich...@michaelgibney.net> wrote:
> >
> > 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!
> >> >
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscr...@solr.apache.org
> For additional commands, e-mail: dev-h...@solr.apache.org
>
>
--
Sincerely yours
Mikhail Khludnev
https://t.me/MUST_SEARCH
A caveat: Cyrillic!
