You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@lucene.apache.org by "Chris M. Hostetter (Jira)" <ji...@apache.org> on 2021/01/07 23:18:00 UTC
[jira] [Reopened] (SOLR-14413) allow timeAllowed and cursorMark
parameters
[ https://issues.apache.org/jira/browse/SOLR-14413?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Chris M. Hostetter reopened SOLR-14413:
---------------------------------------
This new test can fail....
{noformat}
2> 1234796 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 6
2> 1234798 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=*&timeAllowed=1} hits=1000 status=0 QTime=1
2> 1234799 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjMTQy&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234800 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjMTg4&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234801 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjMjMy&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234802 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjMjc4&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234803 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjMzIy&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234804 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjMzY4&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234804 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjNDEy&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234805 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjNDU4&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234806 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjNTAy&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234807 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjNTQ4&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234808 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjNTkz&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234809 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjNjM4&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234810 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjNjgz&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234811 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjNzI4&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234812 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjNzcz&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234813 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjODE4&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234814 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjODYz&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234815 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjOTA4&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234816 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjOTUz&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234817 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjOTk5&timeAllowed=1} hits=1000 status=0 QTime=0
2> 1234817 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjOTk5&timeAllowed=50} hits=1000 status=0 QTime=0
2> 1234818 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=name:a*&fl=id&sort=id+asc&rows=50&sleep=10&cursorMark=AoEjOTk5&timeAllowed=10000} hits=1000 status=0 QTime=0
2> 1234819 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:* (-1688268315991998464)} 0 1
2> 1234822 INFO (searcherExecutor-10458-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
2> 1234822 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 2
2> 1234823 INFO (TEST-CursorPagingTest.testTimeAllowed-seed#[4D63CDC87865C2E0]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTimeAllowed
> java.lang.AssertionError: Should have experienced at least one partialResult
> at __randomizedtesting.SeedInfo.seed([4D63CDC87865C2E0:A906647C23FC1131]:0)
> at org.junit.Assert.fail(Assert.java:89)
> at org.junit.Assert.assertTrue(Assert.java:42)
> at org.apache.solr.CursorPagingTest.testTimeAllowed(CursorPagingTest.java:571)
...
2> NOTE: reproduce with: gradlew test --tests CursorPagingTest.testTimeAllowed -Dtests.seed=4D63CDC87865C2E0 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=en-MO -Dtests.timezone=Africa/Asmara -Dtests.asserts=true -Dtests.file.encoding=UTF-8
{noformat}
Skimming the diff, i think the reason this is happening is because a new {{/select}} handler was added to the config, instead of modifying the existing {{/select}} handler declaration – so when the solrconfig.xml loads the handler with the delay component is ignored and the last one wins...
{noformat}
<requestHandler name="/select" class="solr.SearchHandler">
<arr name="first-components">
<str>delayingSearchComponent</str>
</arr>
</requestHandler>
...
<requestHandler name="/select" class="solr.SearchHandler" default="true" />
{noformat}
...so as a result, the DelayingSearchComponent is never being used.
I suggest renaming the "new" {{/select}} handler to something else – {{/delayed}} for example – and then explicitly refering to that new name with a {{qt}} param in the requests where you expect delays to occur.
----
I'm suspect that once the tests starts to _actually_ use DelayingSearchComponent, you may discover other aspects of this test that are prone to failure on slow jenkins boxes (made even slower by the injected delay)
> allow timeAllowed and cursorMark parameters
> -------------------------------------------
>
> Key: SOLR-14413
> URL: https://issues.apache.org/jira/browse/SOLR-14413
> Project: Solr
> Issue Type: Improvement
> Components: search
> Reporter: John Gallagher
> Assignee: Mike Drob
> Priority: Minor
> Fix For: 8.8, master (9.0)
>
> Attachments: SOLR-14413-bram.patch, SOLR-14413-jg-update1.patch, SOLR-14413-jg-update2.patch, SOLR-14413-jg-update3.patch, SOLR-14413.patch, Screen Shot 2020-10-23 at 10.08.26 PM.png, Screen Shot 2020-10-23 at 10.09.11 PM.png, image-2020-08-18-16-56-41-736.png, image-2020-08-18-16-56-59-178.png, image-2020-08-21-14-18-36-229.png, timeallowed_cursormarks_results.txt
>
> Time Spent: 2h
> Remaining Estimate: 0h
>
> Ever since cursorMarks were introduced in SOLR-5463 in 2014, cursorMark and timeAllowed parameters were not allowed in combination ("Can not search using both cursorMark and timeAllowed")
> , from [QueryComponent.java|#L359]]:
>
> {code:java}
>
> if (null != rb.getCursorMark() && 0 < timeAllowed) {
> // fundamentally incompatible
> throw new SolrException(SolrException.ErrorCode.BAD_REQUEST, "Can not search using both " + CursorMarkParams.CURSOR_MARK_PARAM + " and " + CommonParams.TIME_ALLOWED);
> } {code}
> While theoretically impure to use them in combination, it is often desirable to support cursormarks-style deep paging and attempt to protect Solr nodes from runaway queries using timeAllowed, in the hopes that most of the time, the query completes in the allotted time, and there is no conflict.
>
> However if the query takes too long, it may be preferable to end the query and protect the Solr node and provide the user with a somewhat inaccurate sorted list. As noted in SOLR-6930, SOLR-5986 and others, timeAllowed is frequently used to prevent runaway load. In fact, cursorMark and shards.tolerant are allowed in combination, so any argument in favor of purity would be a bit muddied in my opinion.
>
> This was discussed once in the mailing list that I can find: [https://mail-archives.apache.org/mod_mbox/lucene-solr-user/201506.mbox/%3C5591740B.4080807@elyograg.org%3E] It did not look like there was strong support for preventing the combination.
>
> I have tested cursorMark and timeAllowed combination together, and even when partial results are returned because the timeAllowed is exceeded, the cursorMark response value is still valid and reasonable.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@lucene.apache.org
For additional commands, e-mail: issues-help@lucene.apache.org