Lucene - Core
  1. Lucene - Core
  2. LUCENE-3402

LuceneTestCase shouldn't go crazy if a test fails in an @AfterClass annotated method

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: None
    • Labels:
      None
    • Lucene Fields:
      New

      Description

      An example can be seen here: http://sierranevada.servebeer.com/1314308641.log

      The general problem is this: the assertions and cleanups in lucenetestcase's afterclass should be reordered, and have better error handling.
      In this particular case these were the steps that happened:

      1. AutoCommitTest didn't close its searchers, so SolrTestCaseJ4 threw an assertion exception in its @AfterClass method.
      2. Because the searcher wasn't closed, LuceneTestCase threw an assertion exception about unclosed directories/file handles in its afterClass. Even though the test had already "failed" it ran this assertion because testsFailed is false, since our TestWatchMan isnt aware of failures that happen in @AfterClass methods
      3. Because it threw this exception, it never made it to the part where it resets the random, so the next test blew up in its BeforeClass.

      To add insult to injury, all this happened but we didnt get a random seed printed, so we cant even hope to reproduce the situation.

      After discussion with hossman, we came up with some ideas on how to improve this, and I'm adding some i just thought of, too:

      1. try to divide up these assertions and cleanups in LuceneTestCase: we could use multiple @AfterClass-annotated methods but then i'm not sure we can control the order, which is scary. But one safe thing to do is to put these pieces of code in little methods and afterclass can handle this stuff with try/finally.
      2. think about exposing the testsFailed variable for subclasses that do assertions in their @AfterClasses. otherwise you might not get a random seed, which is bad.
      3. think about upgrading junit, because I know from experimentation that the TestWatchMan (or whatever its replacement is) can "see more" of the test lifecycle and this would probably make a lot of this much cleaner.
      1. LUCENE-3402.patch
        18 kB
        Robert Muir
      2. LUCENE-3402.patch
        18 kB
        Robert Muir

        Activity

        Hide
        Robert Muir added a comment -

        This class is so horrendously out of control right now I'm gonna try to do some rote reorganization/refactoring before tackling this.

        Show
        Robert Muir added a comment - This class is so horrendously out of control right now I'm gonna try to do some rote reorganization/refactoring before tackling this.
        Hide
        Robert Muir added a comment -

        patch makes sure you get some sort of seed in all situations, if we fail in afterclass we don't actually know which test method is responsible (maybe none!),
        but it prints a "reproduce with (Hopefully)" in this case.

        failing in LTC's tearDown() checks should now always give you a seed.

        Here's what it looks like now with the same simulated situation: TestA has a afterClass that opens a Directory, then calls fail()
        In the Solr situation it should look better, since I hacked the Solr test classes to set testsFailed = true if their afterClass checks fail, this way we won't even bother trying to close the directory, but this is just to show it still works even without that, and TestB passes normally.

        junit-sequential:
            [junit] Testsuite: org.apache.lucene.foo.TestA
            [junit] Tests run: 1, Failures: 1, Errors: 1, Time elapsed: 0.135 sec
            [junit] 
            [junit] ------------- Standard Error -----------------
            [junit] NOTE: reproduce with (hopefully): ant test -Dtestcase=TestA -Dtests.seed=7360d49cf342a985:0:-184b15f6f34c023d
            [junit] ------------- ---------------- ---------------
            [junit] Testcase: org.apache.lucene.foo.TestA:	FAILED
            [junit] 
            [junit] junit.framework.AssertionFailedError: 
            [junit] 	at org.apache.lucene.foo.TestA.afterClass(TestA.java:12)
            [junit] 
            [junit] 
            [junit] Testcase: org.apache.lucene.foo.TestA:	Caused an ERROR
            [junit] java.lang.AssertionError: directory of test was not closed, opened from: org.apache.lucene.foo.TestA.afterClass(TestA.java:11)
            [junit] java.lang.RuntimeException: java.lang.AssertionError: directory of test was not closed, opened from: org.apache.lucene.foo.TestA.afterClass(TestA.java:11)
            [junit] 	at org.apache.lucene.util.LuceneTestCase.afterClassLuceneTestCaseJ4(LuceneTestCase.java:462)
            [junit] 	at org.apache.lucene.util.LuceneTestCase.checkResourcesAfterClass(LuceneTestCase.java:519)
            [junit] 	at org.apache.lucene.util.LuceneTestCase.afterClassLuceneTestCaseJ4(LuceneTestCase.java:430)
            [junit] 
            [junit] 
            [junit] TEST org.apache.lucene.foo.TestA FAILED
            [junit] Testsuite: org.apache.lucene.foo.TestB
            [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.006 sec
            [junit] 
            [junit] Tests FAILED
        
        Show
        Robert Muir added a comment - patch makes sure you get some sort of seed in all situations, if we fail in afterclass we don't actually know which test method is responsible (maybe none!), but it prints a "reproduce with (Hopefully)" in this case. failing in LTC's tearDown() checks should now always give you a seed. Here's what it looks like now with the same simulated situation: TestA has a afterClass that opens a Directory, then calls fail() In the Solr situation it should look better, since I hacked the Solr test classes to set testsFailed = true if their afterClass checks fail, this way we won't even bother trying to close the directory, but this is just to show it still works even without that, and TestB passes normally. junit-sequential: [junit] Testsuite: org.apache.lucene.foo.TestA [junit] Tests run: 1, Failures: 1, Errors: 1, Time elapsed: 0.135 sec [junit] [junit] ------------- Standard Error ----------------- [junit] NOTE: reproduce with (hopefully): ant test -Dtestcase=TestA -Dtests.seed=7360d49cf342a985:0:-184b15f6f34c023d [junit] ------------- ---------------- --------------- [junit] Testcase: org.apache.lucene.foo.TestA: FAILED [junit] [junit] junit.framework.AssertionFailedError: [junit] at org.apache.lucene.foo.TestA.afterClass(TestA.java:12) [junit] [junit] [junit] Testcase: org.apache.lucene.foo.TestA: Caused an ERROR [junit] java.lang.AssertionError: directory of test was not closed, opened from: org.apache.lucene.foo.TestA.afterClass(TestA.java:11) [junit] java.lang.RuntimeException: java.lang.AssertionError: directory of test was not closed, opened from: org.apache.lucene.foo.TestA.afterClass(TestA.java:11) [junit] at org.apache.lucene.util.LuceneTestCase.afterClassLuceneTestCaseJ4(LuceneTestCase.java:462) [junit] at org.apache.lucene.util.LuceneTestCase.checkResourcesAfterClass(LuceneTestCase.java:519) [junit] at org.apache.lucene.util.LuceneTestCase.afterClassLuceneTestCaseJ4(LuceneTestCase.java:430) [junit] [junit] [junit] TEST org.apache.lucene.foo.TestA FAILED [junit] Testsuite: org.apache.lucene.foo.TestB [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.006 sec [junit] [junit] Tests FAILED
        Hide
        Robert Muir added a comment -

        didn't mean to delete the fieldcache sanity-checking commentary, also print the debugginginfo (JRE/OS) if we fail in afterclass.

        Show
        Robert Muir added a comment - didn't mean to delete the fieldcache sanity-checking commentary, also print the debugginginfo (JRE/OS) if we fail in afterclass.
        Hide
        Robert Muir added a comment -

        I'm gonna give this patch a try, if things go crazy i'll back it out.

        Show
        Robert Muir added a comment - I'm gonna give this patch a try, if things go crazy i'll back it out.
        Hide
        Uwe Schindler added a comment -

        Go for it.

        Show
        Uwe Schindler added a comment - Go for it.

          People

          • Assignee:
            Unassigned
            Reporter:
            Robert Muir
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development