I actually know what this one is now.

Jetty is shutting down, and the graceful timeout is too low, and so jetty interrupts the webapp, and while we are waiting for merges to finish on IW#close, an interrupt is thrown and we stop waiting. So the directory is then closed out from under the merge thread. So really, mostly a test issue it seems?

So I changed out jetty instances in tests to a 30 second graceful shutdown. Tests went from 6 minutes for me, to 33 minutes. I won't make this fix for now :) One idea is to perhaps do it just for this test - but even then it makes the test *much* longer, and there is no reason it can't happen on other tests that use jetty instances. It just happens to only show up in the test currently AFAICT.

On May 25, 2012, at 5:30 AM, Apache Jenkins Server wrote:

> Build: https://builds.apache.org/job/Solr-trunk/1865/
>
> 1 tests failed.
> REGRESSION:  org.apache.solr.cloud.RecoveryZkTest.testDistribSearch
>
> Error Message:
> Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #2,6,]
>
> Stack Trace:
> java.lang.RuntimeException: Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #2,6,]
> at com.carrotsearch.randomizedtesting.RunnerThreadGroup.processUncaught(RunnerThreadGroup.java:96)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:857)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.access$700(RandomizedRunner.java:132)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$3$1.run(RandomizedRunner.java:669)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:695)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:734)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:745)
> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
> at org.apache.lucene.util.TestRuleReportUncaughtExceptions$1.evaluate(TestRuleReportUncaughtExceptions.java:68)
> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:38)
> at org.apache.lucene.util.TestRuleIcuHack$1.evaluate(TestRuleIcuHack.java:51)
> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
> at org.apache.lucene.util.TestRuleNoInstanceHooksOverrides$1.evaluate(TestRuleNoInstanceHooksOverrides.java:53)
> at org.apache.lucene.util.TestRuleNoStaticHooksShadowing$1.evaluate(TestRuleNoStaticHooksShadowing.java:52)
> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:36)
> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:56)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSuite(RandomizedRunner.java:605)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.access$400(RandomizedRunner.java:132)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$2.run(RandomizedRunner.java:551)
> Caused by: org.apache.lucene.index.MergePolicy$MergeException: org.apache.lucene.store.AlreadyClosedException: this Directory is closed
> at __randomizedtesting.SeedInfo.seed([8B4A827F28B6F16]:0)
> at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:507)
> at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:480)
> Caused by: org.apache.lucene.store.AlreadyClosedException: this Directory is closed
> at org.apache.lucene.store.Directory.ensureOpen(Directory.java:244)
> at org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:241)
> at org.apache.lucene.index.IndexFileDeleter.refresh(IndexFileDeleter.java:345)

- Mark Miller
lucidimagination.com

Just thinking out loud... shouldn't solr(cloud) manage such situation
gracefully? I mean in real life solr instances can be killed or even
whole servers can go away. Would it be ok to ignore that exception
instead?
--
 Sami Siren

On Fri, May 25, 2012 at 3:01 PM, Mark Miller <[EMAIL PROTECTED]> wrote:
> I actually know what this one is now.
>
> Jetty is shutting down, and the graceful timeout is too low, and so jetty interrupts the webapp, and while we are waiting for merges to finish on IW#close, an interrupt is thrown and we stop waiting. So the directory is then closed out from under the merge thread. So really, mostly a test issue it seems?
>
> So I changed out jetty instances in tests to a 30 second graceful shutdown. Tests went from 6 minutes for me, to 33 minutes. I won't make this fix for now :) One idea is to perhaps do it just for this test - but even then it makes the test *much* longer, and there is no reason it can't happen on other tests that use jetty instances. It just happens to only show up in the test currently AFAICT.
>
> On May 25, 2012, at 5:30 AM, Apache Jenkins Server wrote:
>
>> Build: https://builds.apache.org/job/Solr-trunk/1865/
>>
>> 1 tests failed.
>> REGRESSION:  org.apache.solr.cloud.RecoveryZkTest.testDistribSearch
>>
>> Error Message:
>> Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #2,6,]
>>
>> Stack Trace:
>> java.lang.RuntimeException: Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #2,6,]
>>       at com.carrotsearch.randomizedtesting.RunnerThreadGroup.processUncaught(RunnerThreadGroup.java:96)
>>       at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:857)
>>       at com.carrotsearch.randomizedtesting.RandomizedRunner.access$700(RandomizedRunner.java:132)
>>       at com.carrotsearch.randomizedtesting.RandomizedRunner$3$1.run(RandomizedRunner.java:669)
>>       at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:695)
>>       at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:734)
>>       at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:745)
>>       at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
>>       at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
>>       at org.apache.lucene.util.TestRuleReportUncaughtExceptions$1.evaluate(TestRuleReportUncaughtExceptions.java:68)
>>       at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:38)
>>       at org.apache.lucene.util.TestRuleIcuHack$1.evaluate(TestRuleIcuHack.java:51)
>>       at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
>>       at org.apache.lucene.util.TestRuleNoInstanceHooksOverrides$1.evaluate(TestRuleNoInstanceHooksOverrides.java:53)
>>       at org.apache.lucene.util.TestRuleNoStaticHooksShadowing$1.evaluate(TestRuleNoStaticHooksShadowing.java:52)
>>       at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:36)
>>       at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
>>       at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:56)
>>       at com.carrotsearch.randomizedtesting.RandomizedRunner.runSuite(RandomizedRunner.java:605)
>>       at com.carrotsearch.randomizedtesting.RandomizedRunner.access$400(RandomizedRunner.java:132)
>>       at com.carrotsearch.randomizedtesting.RandomizedRunner$2.run(RandomizedRunner.java:551)
>> Caused by: org.apache.lucene.index.MergePolicy$MergeException: org.apache.lucene.store.AlreadyClosedException: this Directory is closed
>>       at __randomizedtesting.SeedInfo.seed([8B4A827F28B6F16]:0)
>>       at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:507)

On May 25, 2012, at 8:11 AM, Sami Siren wrote:

> Just thinking out loud... shouldn't solr(cloud) manage such situation
> gracefully?

Currently, you can handle it gracefully if you up the graceful timeout in jetty. It's easy enough to do that with the jetty we ship, but it's painful (extremely it seems) to do it in tests.

In any case, I don't think it hurts anything practically? The merge thread fails, and so simply, you don't get those merges I think? The problem with the tests is that the exception is thrown from the merge thread. We have no affect on that from Solr - the test framework picks up an uncaught exception in the thread, and our goose is cooked.

> I mean in real life solr instances can be killed or even
> whole servers can go away. Would it be ok to ignore that exception
> instead?

It's at the Lucene level really, so unless we try really hard to work around it, we would have to figure out if something different made sense there I think.

Right now, if its waiting for merges to finish and gets interrupted, it throws an interrupted exception. Unless we explicitly try and kill the current merge threads, I'd think that could be a problem in any general code. You close the IW with wait for merges to finish = true, then you start closing other resources, because you assume you are done with the IW, but in fact merges can still be occurring if the thread was interrupted. And you might close resources merging depends on (ie the directory).

Lucene does not like interruptions in other cases as well, but unfortunately, running in a webapp, we can't easily always avoid them it seems.

> --
> Sami Siren
>
> On Fri, May 25, 2012 at 3:01 PM, Mark Miller <[EMAIL PROTECTED]> wrote:
>> I actually know what this one is now.
>>
>> Jetty is shutting down, and the graceful timeout is too low, and so jetty interrupts the webapp, and while we are waiting for merges to finish on IW#close, an interrupt is thrown and we stop waiting. So the directory is then closed out from under the merge thread. So really, mostly a test issue it seems?
>>
>> So I changed out jetty instances in tests to a 30 second graceful shutdown. Tests went from 6 minutes for me, to 33 minutes. I won't make this fix for now :) One idea is to perhaps do it just for this test - but even then it makes the test *much* longer, and there is no reason it can't happen on other tests that use jetty instances. It just happens to only show up in the test currently AFAICT.
>>
>> On May 25, 2012, at 5:30 AM, Apache Jenkins Server wrote:
>>
>>> Build: https://builds.apache.org/job/Solr-trunk/1865/
>>>
>>> 1 tests failed.
>>> REGRESSION:  org.apache.solr.cloud.RecoveryZkTest.testDistribSearch
>>>
>>> Error Message:
>>> Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #2,6,]
>>>
>>> Stack Trace:
>>> java.lang.RuntimeException: Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #2,6,]
>>>       at com.carrotsearch.randomizedtesting.RunnerThreadGroup.processUncaught(RunnerThreadGroup.java:96)
>>>       at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:857)
>>>       at com.carrotsearch.randomizedtesting.RandomizedRunner.access$700(RandomizedRunner.java:132)
>>>       at com.carrotsearch.randomizedtesting.RandomizedRunner$3$1.run(RandomizedRunner.java:669)
>>>       at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:695)
>>>       at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:734)
>>>       at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:745)
>>>       at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
>>>       at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
>>>       at org.apache.lucene.util.TestRuleReportUncaughtExceptions$1.evaluate(TestRuleReportUncaughtExceptions.java:68)

- Mark Miller
lucidimagination.com

On Fri, May 25, 2012 at 3:44 PM, Mark Miller <[EMAIL PROTECTED]> wrote:
>
> On May 25, 2012, at 8:11 AM, Sami Siren wrote:
>
>> Just thinking out loud... shouldn't solr(cloud) manage such situation
>> gracefully?
>
> Currently, you can handle it gracefully if you up the graceful timeout in jetty. It's easy enough to do that with the jetty we ship, but it's painful (extremely it seems) to do it in tests.
>
> In any case, I don't think it hurts anything practically?

that was my point.

> the test framework picks up an uncaught exception in the thread, and our goose is cooked.

by ignoring the exception I was trying to say that it should be
ignored from POV of test framework, ie not fail the build. I now
understand that it might not actually solve the issue...

--
 Sami Siren

---------------------------------------------------------------------

On May 25, 2012, at 9:00 AM, Sami Siren wrote:

> by ignoring the exception I was trying to say that it should be
> ignored from POV of test framework, ie not fail the build. I now
> understand that it might not actually solve the issue...

Yeah, I suppose if we could tell the test framework, for this test, ignore this expected uncaught exception, that might help.

Usually you can work around this type of thing more cleanly though - so I don't know if it's worth the effort or extra code - if this ends up being it's only use case, it's hard to argue we add the capability. And I suspect it would mean conning dawid to suck it up and update our test jars? I think it also has a lot of potential for abuse.

But the fail sucks too, so I don't know...
- Mark Miller
lucidimagination.com


---------------------------------------------------------------------

> Yeah, I suppose if we could tell the test framework, for this test, ignore this expected uncaught exception, that might help.

This is not a problem technically; for a single test suite I'd just
wrap everything with a rule that would temporarily capture unhandled
exceptions, that's it. I suspect a lot of other exceptions/ problems
we're seeing are due to leaked threads and unclosed jetty/zk sockets,
so I'd rather work on trying to make this more efficient.

I am pretty swamped with other things at the moment but if you can
give me a test case that somehow shows these "long" jetty shutdown
times it'd be a big help.

Dawid

---------------------------------------------------------------------

On Fri, May 25, 2012 at 9:54 AM, Mark Miller <[EMAIL PROTECTED]> wrote:
>
> On May 25, 2012, at 9:00 AM, Sami Siren wrote:
>
>> by ignoring the exception I was trying to say that it should be
>> ignored from POV of test framework, ie not fail the build. I now
>> understand that it might not actually solve the issue...
>
> Yeah, I suppose if we could tell the test framework, for this test, ignore this expected uncaught exception, that might help.
>
> Usually you can work around this type of thing more cleanly though - so I don't know if it's worth the effort or extra code - if this ends up being it's only use case, it's hard to argue we add the capability. And I suspect it would mean conning dawid to suck it up and update our test jars? I think it also has a lot of potential for abuse.
>

the exception-from-another-thread is just an uncaught exception
handler. you can replace it with your own that handles things
differently,
and restore the old one back.

Here's an example of one that does this when the exception is really a jvm bug:

http://svn.apache.org/repos/asf/lucene/dev/branches/lucene_solr_3_6/lucene/contrib/analyzers/common/src/test/org/apache/lucene/analysis/miscellaneous/PatternAnalyzerTest.java

--
lucidimagination.com

---------------------------------------------------------------------

>> Yeah, I suppose if we could tell the test framework, for this test, ignore this expected uncaught exception, that might help.

The point of handling uncaught exceptions, thread leaks etc. at the
test framework's level is in the essence to capture bad tests or
unanticipated conditions, not failures that we know of or can predict.
So is interrupting leaked threads (because there is no way to do it
otherwise if you don't know anything about a given thread).

This said, there are obviously ways to handle the above situation --
from trying to speed up jetty shutdown to capturing that uncaught
error. Why is jetty so slow to shutdown? What does it mean "slow"?

> Tests went from 6 minutes for me, to 33 minutes.

I don't think this can be explained by shutting down jetty... this
seems too long. Can you provide a repeatable test case what would
demonstrate the failure you mentioned? Once I have it it'll be easier
to try to come up with workarounds.

Dawid

---------------------------------------------------------------------

On May 25, 2012, at 12:26 PM, Dawid Weiss wrote:

> I don't think this can be explained by shutting down jetty... this
> seems too long. Can you provide a repeatable test case what would
> demonstrate the failure you mentioned? Once I have it it'll be easier
> to try to come up with workarounds.
>
> Dawid

No, I don't think it would be that easy to make a repeatable test case, so I don't think I'll have near term time for it. This one is not really a practical issue, so low on my priority list. It repeats on jenkins on the rare occasion ;)

Jetty seems more likely than the test framework to me - IW#close happens well before the test is over, and in the main thread, and that is what is interrupted (waiting for merges to finish)...and Jetty will send an interrupt on shutdown after the graceful shutdown timeout. Increasing that timeout will drastically lessen the chances of it happening - but we start and shutdown jetty serially, and that is likely why its so much longer - some tests use a lot of jetties.

Trying to stop jetties in parallel might be one thing to try obviously.

- Mark Miller
lucidimagination.com


---------------------------------------------------------------------

On May 25, 2012, at 2:07 PM, Mark Miller wrote:

> Trying to stop jetties in parallel might be one thing to try obviously.

But I still expected to see an ugly slowdown on many tests (eg even 30 seconds * 10 tests is a significant add).

It may be we simply have to do it in this one test though (add to the graceful exit time) - other tests don't have enough indexing occurring to cause long end merges I think.

- Mark Miller
lucidimagination.com


---------------------------------------------------------------------

On Fri, May 25, 2012 at 9:15 PM, Mark Miller <[EMAIL PROTECTED]> wrote:
>
> On May 25, 2012, at 2:07 PM, Mark Miller wrote:
>
>> Trying to stop jetties in parallel might be one thing to try obviously.
>
> But I still expected to see an ugly slowdown on many tests (eg even 30 seconds * 10 tests is a significant add).
>
> It may be we simply have to do it in this one test though (add to the graceful exit time) - other tests don't have enough indexing occurring to cause long end merges I think.

can't you use a special MP that only merges small segments to prevent
large merges?

simon
>
> - Mark Miller
> lucidimagination.com
>
>
>
>
>
>
>
>
>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [EMAIL PROTECTED]
> For additional commands, e-mail: [EMAIL PROTECTED]
>

---------------------------------------------------------------------