Solr
  1. Solr
  2. SOLR-2739

TestSqlEntityProcessorDelta.testNonWritablePersistFile failures on some systems

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 3.3
    • Fix Version/s: 3.5, 4.0-ALPHA
    • Component/s: None
    • Labels:
      None

      Description

      Shawn Heisey noted on the mailing list that he was getting consistent failures from TestSqlEntityProcessorDelta.testNonWritablePersistFile on his machine.

      I can't reproduce his exact failures, but the test is hinky enough that i want to try and clean it up.

        Activity

        Hide
        Hoss Man added a comment -

        Failure Shawn reported seeing consistently with all seeds...

            [junit] 08/08/2011 10:05:13 م org.apache.solr.SolrTestCaseJ4 assertQ
            [junit] SEVERE: REQUEST FAILED: xpath=//*[@numFound='0']
            [junit]     xml response was: <?xml version="1.0" encoding="UTF-8"?>
            [junit] <response>
            [junit] <lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="start">0</str><str name="q">id:1</str><str name="qt">standard</str><str name="rows">20</str><str name="version">2.2</str></lst></lst><result name="response" numFound="1" start="0"><doc><arr name="desc"><str>hello</str></arr><str name="id">1</str><date name="timestamp">2011-08-08T19:05:13.353Z</date></doc></result>
            [junit] </response>
            [junit]
            [junit]     request was:start=0&q=id:1&qt=standard&rows=20&version=2.2
            [junit] 08/08/2011 10:05:13 م org.apache.solr.common.SolrException log
            [junit] SEVERE: REQUEST FAILED: start=0&q=id:1&qt=standard&rows=20&version=2.2:java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='0']
            [junit]     xml response was: <?xml version="1.0" encoding="UTF-8"?>
            [junit] <response>
            [junit] <lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="start">0</str><str name="q">id:1</str><str name="qt">standard</str><str name="rows">20</str><str name="version">2.2</str></lst></lst><result name="response" numFound="1" start="0"><doc><arr name="desc"><str>hello</str></arr><str name="id">1</str><date name="timestamp">2011-08-08T19:05:13.353Z</date></doc></result>
            [junit] </response>
            [junit]
            [junit]     request was:start=0&q=id:1&qt=standard&rows=20&version=2.2
            [junit]     at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:377)
            [junit]     at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:351)
            [junit]     at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testNonWritablePersistFile(TestSqlEntityProcessorDelta.java:121)
            [junit]     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            [junit]     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
            [junit]     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
            [junit]     at java.lang.reflect.Method.invoke(Method.java:597)
            [junit]     at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
            [junit]     at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
            [junit]     at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
            [junit]     at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
            [junit]     at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48)
            [junit]     at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
            [junit]     at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
            [junit]     at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
            [junit]     at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1339)
            [junit]     at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1241)
            [junit]     at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
            [junit]     at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
            [junit]     at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
            [junit]     at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
            [junit]     at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
            [junit]     at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
            [junit]     at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
            [junit]     at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
            [junit]     at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
            [junit]     at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
            [junit]     at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
            [junit]     at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:743)
            [junit]
            [junit] NOTE: reproduce with: ant test -Dtestcase=TestSqlEntityProcessorDelta -Dtestmethod=testNonWritablePersistFile -Dtests.seed=-792d6c110a4b6e96:1c3eeb109a03bb0b:-1ac8e3d1d169d356
            [junit] NOTE: test params are: locale=ar_SA, timezone=Asia/Amman
            [junit] NOTE: all tests run in this JVM:
            [junit] [TestCachedSqlEntityProcessor, TestClobTransformer, TestContentStreamDataSource, TestDataConfig, TestDateFormatTransformer, TestDocBuilder, TestDocBuilder2, TestDocBuilderThreaded, TestEntityProcessorBase, TestErrorHandling, TestEvaluatorBag, TestFieldReader, TestFileListEntityProcessor, TestJdbcDataSource, TestLineEntityProcessor, TestNumberFormatTransformer, TestPlainTextEntityProcessor, TestRegexTransformer, TestScriptTransformer, TestSqlEntityProcessor, TestSqlEntityProcessor2, TestSqlEntityProcessorDelta]
            [junit] NOTE: Linux 2.6.18-238.12.1.el5.centos.plusxen amd64/Sun Microsystems Inc. 1.6.0_26 (64-bit)/cpus=3,threads=4,free=109853160,total=195952640
        

        i can't reproduce, this exact error and i don't fully understand the test, but it seems to be attempting to verify that if the dataimport.properties file can't be written to, then after it "does some stuff", there are still no docs in the index.

        the problem is that it conditionally tries to "do stuff" if the JVM says that it was able to mark the dataimport.properties as read only w/o any indication of this in the test output. on top of that: the file it creates & attempts to mark read only is only cleaned up if all of this succeeds - and from my own testing that can cause problems in other tests in this class.

        I'm going to change this silent conditional to an assumption, and move the file deletion logic into a higher up finally block, and see if that change the behavior on shawns box (if he starts seeing a message about the assumption failed, we'll have made progress)

        Show
        Hoss Man added a comment - Failure Shawn reported seeing consistently with all seeds... [junit] 08/08/2011 10:05:13 م org.apache.solr.SolrTestCaseJ4 assertQ [junit] SEVERE: REQUEST FAILED: xpath=//*[@numFound='0'] [junit] xml response was: <?xml version="1.0" encoding="UTF-8"?> [junit] <response> [junit] <lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="start">0</str><str name="q">id:1</str><str name="qt">standard</str><str name="rows">20</str><str name="version">2.2</str></lst></lst><result name="response" numFound="1" start="0"><doc><arr name="desc"><str>hello</str></arr><str name="id">1</str><date name="timestamp">2011-08-08T19:05:13.353Z</date></doc></result> [junit] </response> [junit] [junit] request was:start=0&q=id:1&qt=standard&rows=20&version=2.2 [junit] 08/08/2011 10:05:13 م org.apache.solr.common.SolrException log [junit] SEVERE: REQUEST FAILED: start=0&q=id:1&qt=standard&rows=20&version=2.2:java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='0'] [junit] xml response was: <?xml version="1.0" encoding="UTF-8"?> [junit] <response> [junit] <lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="start">0</str><str name="q">id:1</str><str name="qt">standard</str><str name="rows">20</str><str name="version">2.2</str></lst></lst><result name="response" numFound="1" start="0"><doc><arr name="desc"><str>hello</str></arr><str name="id">1</str><date name="timestamp">2011-08-08T19:05:13.353Z</date></doc></result> [junit] </response> [junit] [junit] request was:start=0&q=id:1&qt=standard&rows=20&version=2.2 [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:377) [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:351) [junit] at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testNonWritablePersistFile(TestSqlEntityProcessorDelta.java:121) [junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [junit] at java.lang.reflect.Method.invoke(Method.java:597) [junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) [junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) [junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) [junit] at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) [junit] at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) [junit] at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) [junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31) [junit] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1339) [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1241) [junit] at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) [junit] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) [junit] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) [junit] at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) [junit] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) [junit] at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) [junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31) [junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:236) [junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420) [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911) [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:743) [junit] [junit] NOTE: reproduce with: ant test -Dtestcase=TestSqlEntityProcessorDelta -Dtestmethod=testNonWritablePersistFile -Dtests.seed=-792d6c110a4b6e96:1c3eeb109a03bb0b:-1ac8e3d1d169d356 [junit] NOTE: test params are: locale=ar_SA, timezone=Asia/Amman [junit] NOTE: all tests run in this JVM: [junit] [TestCachedSqlEntityProcessor, TestClobTransformer, TestContentStreamDataSource, TestDataConfig, TestDateFormatTransformer, TestDocBuilder, TestDocBuilder2, TestDocBuilderThreaded, TestEntityProcessorBase, TestErrorHandling, TestEvaluatorBag, TestFieldReader, TestFileListEntityProcessor, TestJdbcDataSource, TestLineEntityProcessor, TestNumberFormatTransformer, TestPlainTextEntityProcessor, TestRegexTransformer, TestScriptTransformer, TestSqlEntityProcessor, TestSqlEntityProcessor2, TestSqlEntityProcessorDelta] [junit] NOTE: Linux 2.6.18-238.12.1.el5.centos.plusxen amd64/Sun Microsystems Inc. 1.6.0_26 (64-bit)/cpus=3,threads=4,free=109853160,total=195952640 i can't reproduce, this exact error and i don't fully understand the test, but it seems to be attempting to verify that if the dataimport.properties file can't be written to, then after it "does some stuff", there are still no docs in the index. the problem is that it conditionally tries to "do stuff" if the JVM says that it was able to mark the dataimport.properties as read only w/o any indication of this in the test output. on top of that: the file it creates & attempts to mark read only is only cleaned up if all of this succeeds - and from my own testing that can cause problems in other tests in this class. I'm going to change this silent conditional to an assumption, and move the file deletion logic into a higher up finally block, and see if that change the behavior on shawns box (if he starts seeing a message about the assumption failed, we'll have made progress)
        Hide
        Hoss Man added a comment -

        Committed revision 1164287 - trunk
        Committed revision 1164289 - 3x

        This should make the test sane enough that it either works, or correctly skips because of the assumption, on all platforms.

        leaving open to see if Shawn chimes in with any followup comments

        Show
        Hoss Man added a comment - Committed revision 1164287 - trunk Committed revision 1164289 - 3x This should make the test sane enough that it either works, or correctly skips because of the assumption, on all platforms. leaving open to see if Shawn chimes in with any followup comments
        Hide
        Shawn Heisey added a comment -

        I continue to get a failure. It looks like it's checking to make sure numFound is 0, but it's seeing 1, which is what it did before. The exception does look different, and now it's caused by another exception. Failure text from the new branch_3x:

            [junit] ------------- Standard Error -----------------
            [junit] NOTE: reproduce with: ant test -Dtestcase=TestSqlEntityProcessorDelta -Dtestmethod=testNonWritablePersistFile -Dtests.seed=-5706afed1ddb3d06:65ec54c2cd2efa63:3ba1f077e387d65
            [junit] NOTE: test params are: locale=en_IE, timezone=Europe/Berlin
            [junit] NOTE: all tests run in this JVM:
            [junit] [TestCachedSqlEntityProcessor, TestClobTransformer, TestContentStreamDataSource, TestDataConfig, TestDateFormatTransformer, TestDocBuilder, TestDocBuilder2, TestDocBuilderThreaded, TestEntityProcessorBase, TestErrorHandling, TestEvaluatorBag, TestFieldReader, TestFileListEntityProcessor, TestJdbcDataSource, TestLineEntityProcessor, TestNumberFormatTransformer, TestPlainTextEntityProcessor, TestRegexTransformer, TestScriptTransformer, TestSqlEntityProcessor, TestSqlEntityProcessor2, TestSqlEntityProcessorDelta]
            [junit] NOTE: Linux 2.6.18-238.12.1.el5.centos.plusxen amd64/Sun Microsystems Inc. 1.6.0_26 (64-bit)/cpus=3,threads=4,free=193825632,total=247136256
            [junit] ------------- ---------------- ---------------
            [junit] Testcase: testNonWritablePersistFile(org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta):       Caused an ERROR
            [junit] Exception during query
            [junit] java.lang.RuntimeException: Exception during query
            [junit]     at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:385)
            [junit]     at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:352)
            [junit]     at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testNonWritablePersistFile(TestSqlEntityProcessorDelta.java:124)
            [junit]     at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:147)
            [junit]     at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:50)
            [junit] Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='0']
            [junit]     xml response was: <?xml version="1.0" encoding="UTF-8"?>
            [junit] <response>
            [junit] <lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int><lst name="params"><str name="start">0</str><str name="q">id:1</str><str name="qt">standard</str><str name="rows">20</str><str name="version">2.2</str></lst></lst><result name="response" numFound="1" start="0"><doc><arr name="desc"><str>hello</str></arr><str name="id">1</str><date name="timestamp">2011-09-02T01:45:21.014Z</date></doc></result>
            [junit] </response>
            [junit]
            [junit]     request was:start=0&q=id:1&qt=standard&rows=20&version=2.2
            [junit]     at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:378)
        
        Show
        Shawn Heisey added a comment - I continue to get a failure. It looks like it's checking to make sure numFound is 0, but it's seeing 1, which is what it did before. The exception does look different, and now it's caused by another exception. Failure text from the new branch_3x: [junit] ------------- Standard Error ----------------- [junit] NOTE: reproduce with: ant test -Dtestcase=TestSqlEntityProcessorDelta -Dtestmethod=testNonWritablePersistFile -Dtests.seed=-5706afed1ddb3d06:65ec54c2cd2efa63:3ba1f077e387d65 [junit] NOTE: test params are: locale=en_IE, timezone=Europe/Berlin [junit] NOTE: all tests run in this JVM: [junit] [TestCachedSqlEntityProcessor, TestClobTransformer, TestContentStreamDataSource, TestDataConfig, TestDateFormatTransformer, TestDocBuilder, TestDocBuilder2, TestDocBuilderThreaded, TestEntityProcessorBase, TestErrorHandling, TestEvaluatorBag, TestFieldReader, TestFileListEntityProcessor, TestJdbcDataSource, TestLineEntityProcessor, TestNumberFormatTransformer, TestPlainTextEntityProcessor, TestRegexTransformer, TestScriptTransformer, TestSqlEntityProcessor, TestSqlEntityProcessor2, TestSqlEntityProcessorDelta] [junit] NOTE: Linux 2.6.18-238.12.1.el5.centos.plusxen amd64/Sun Microsystems Inc. 1.6.0_26 (64-bit)/cpus=3,threads=4,free=193825632,total=247136256 [junit] ------------- ---------------- --------------- [junit] Testcase: testNonWritablePersistFile(org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta): Caused an ERROR [junit] Exception during query [junit] java.lang.RuntimeException: Exception during query [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:385) [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:352) [junit] at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testNonWritablePersistFile(TestSqlEntityProcessorDelta.java:124) [junit] at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:147) [junit] at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:50) [junit] Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='0'] [junit] xml response was: <?xml version="1.0" encoding="UTF-8"?> [junit] <response> [junit] <lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int><lst name="params"><str name="start">0</str><str name="q">id:1</str><str name="qt">standard</str><str name="rows">20</str><str name="version">2.2</str></lst></lst><result name="response" numFound="1" start="0"><doc><arr name="desc"><str>hello</str></arr><str name="id">1</str><date name="timestamp">2011-09-02T01:45:21.014Z</date></doc></result> [junit] </response> [junit] [junit] request was:start=0&q=id:1&qt=standard&rows=20&version=2.2 [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:378)
        Hide
        Shawn Heisey added a comment -

        This is still a problem. As it seems to be specific to my environment, I am very interested in tracking it down, but I have no idea where to begin. My current test setup is CentOS 6, ext4, Oracle Java 1.6.0_27-b07. Can you give me pointers on how to figure out what the problem is? Do you need me to provide any more information than I have already?

        Steps to reproduce current failures on my system from the commandline with 3.4 or branch_3x:

        svn co https://svn.apache.org/repos/asf/lucene/dev/branches/lucene_solr_3_4 lucene_solr_3_4
        cd lucene_solr_3_4/solr
        ant test

        svn co https://svn.apache.org/repos/asf/lucene/dev/branches/branch_3x branch_3x
        cd branch_3x/solr
        ant test

        Some additional info:

        [root@bigindy5 src]# rpm -qa | egrep "ant|junit|java"
        java-1.6.0-openjdk-1.6.0.0-1.36.b17.el6_0.x86_64
        java-1.6.0-sun-1.6.0.27-1.0.cf.x86_64
        ant-nodeps-1.7.1-13.el6.x86_64
        wpa_supplicant-0.6.8-10.el6.x86_64
        libvirt-java-devel-0.4.5-2.el6.noarch
        java-1.6.0-sun-devel-1.6.0.27-1.0.cf.x86_64
        enchant-1.5.0-4.el6.x86_64
        tzdata-java-2011g-1.el6.noarch
        java_cup-0.10k-5.el6.x86_64
        junit-3.8.2-6.5.el6.x86_64
        java-1.6.0-sun-plugin-1.6.0.27-1.0.cf.x86_64
        anthy-9100h-10.1.el6.x86_64
        libvirt-java-0.4.5-2.el6.noarch
        java-1.5.0-gcj-1.5.0.0-29.1.el6.x86_64
        ant-1.7.1-13.el6.x86_64
        ant-junit-1.7.1-13.el6.x86_64
        ibus-anthy-1.2.1-1.el6.x86_64
        java-1.6.0-sun-jdbc-1.6.0.27-1.0.cf.x86_64
        junit4-4.5-5.3.el6.noarch

        [root@bigindy5 src]# java -version
        java version "1.6.0_27"
        Java(TM) SE Runtime Environment (build 1.6.0_27-b07)
        Java HotSpot(TM) 64-Bit Server VM (build 20.2-b06, mixed mode)

        [root@bigindy5 src]# uname -a
        Linux bigindy5 2.6.32-71.29.1.el6.centos.plus.x86_64 #1 SMP Sun Jun 26 16:27:27 BST 2011 x86_64 x86_64 x86_64 GNU/Linux

        Show
        Shawn Heisey added a comment - This is still a problem. As it seems to be specific to my environment, I am very interested in tracking it down, but I have no idea where to begin. My current test setup is CentOS 6, ext4, Oracle Java 1.6.0_27-b07. Can you give me pointers on how to figure out what the problem is? Do you need me to provide any more information than I have already? Steps to reproduce current failures on my system from the commandline with 3.4 or branch_3x: svn co https://svn.apache.org/repos/asf/lucene/dev/branches/lucene_solr_3_4 lucene_solr_3_4 cd lucene_solr_3_4/solr ant test svn co https://svn.apache.org/repos/asf/lucene/dev/branches/branch_3x branch_3x cd branch_3x/solr ant test Some additional info: [root@bigindy5 src] # rpm -qa | egrep "ant|junit|java" java-1.6.0-openjdk-1.6.0.0-1.36.b17.el6_0.x86_64 java-1.6.0-sun-1.6.0.27-1.0.cf.x86_64 ant-nodeps-1.7.1-13.el6.x86_64 wpa_supplicant-0.6.8-10.el6.x86_64 libvirt-java-devel-0.4.5-2.el6.noarch java-1.6.0-sun-devel-1.6.0.27-1.0.cf.x86_64 enchant-1.5.0-4.el6.x86_64 tzdata-java-2011g-1.el6.noarch java_cup-0.10k-5.el6.x86_64 junit-3.8.2-6.5.el6.x86_64 java-1.6.0-sun-plugin-1.6.0.27-1.0.cf.x86_64 anthy-9100h-10.1.el6.x86_64 libvirt-java-0.4.5-2.el6.noarch java-1.5.0-gcj-1.5.0.0-29.1.el6.x86_64 ant-1.7.1-13.el6.x86_64 ant-junit-1.7.1-13.el6.x86_64 ibus-anthy-1.2.1-1.el6.x86_64 java-1.6.0-sun-jdbc-1.6.0.27-1.0.cf.x86_64 junit4-4.5-5.3.el6.noarch [root@bigindy5 src] # java -version java version "1.6.0_27" Java(TM) SE Runtime Environment (build 1.6.0_27-b07) Java HotSpot(TM) 64-Bit Server VM (build 20.2-b06, mixed mode) [root@bigindy5 src] # uname -a Linux bigindy5 2.6.32-71.29.1.el6.centos.plus.x86_64 #1 SMP Sun Jun 26 16:27:27 BST 2011 x86_64 x86_64 x86_64 GNU/Linux
        Hide
        Shawn Heisey added a comment -

        I've also been seeing intermittent failures in TestCSVLoader, in both 3.4 and 3x. The nature of the failure is the same as on TestSqlEntityProcessorDelta, numFound shows a different value than what the test expects. If I run the following command over and over, sometimes it will fail, but mostly it will pass:

        ant test -Dtestcase=TestCSVLoader -Dtestmethod=testCommitWithin

        Here's one failure on lucene_solr_3_4:

        [junit] Testsuite: org.apache.solr.handler.TestCSVLoader
        [junit] Testcase: testCommitWithin(org.apache.solr.handler.TestCSVLoader): Caused an ERROR
        [junit] Exception during query
        [junit] java.lang.RuntimeException: Exception during query
        [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:385)
        [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:352)
        [junit] at org.apache.solr.handler.TestCSVLoader.testCommitWithin(TestCSVLoader.java:121)
        [junit] at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:147)
        [junit] at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:50)
        [junit] Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='3']
        [junit] xml response was: <?xml version="1.0" encoding="UTF-8"?>
        [junit] <response>
        [junit] <responseHeader><status>0</status><QTime>0</QTime></responseHeader><result name="response" numFound="0" start="0"/>
        [junit] </response>
        [junit]
        [junit] request was:start=0&q=id:[100+TO+110]&qt=standard&rows=20&version=2.0
        [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:378)
        [junit]
        [junit]
        [junit] Tests run: 5, Failures: 0, Errors: 1, Time elapsed: 29.793 sec
        [junit]
        [junit] ------------- Standard Error -----------------
        [junit] 2011-09-15 12:46:04.PD org.apache.solr.SolrTestCaseJ4 assertQ
        [junit] SEVERE: REQUEST FAILED: xpath=//*[@numFound='3']
        [junit] xml response was: <?xml version="1.0" encoding="UTF-8"?>
        [junit] <response>
        [junit] <responseHeader><status>0</status><QTime>0</QTime></responseHeader><result name="response" numFound="0" start="0"/>
        [junit] </response>
        [junit]
        [junit] request was:start=0&q=id:[100+TO+110]&qt=standard&rows=20&version=2.0
        [junit] 2011-09-15 12:46:04.PD org.apache.solr.common.SolrException log
        [junit] SEVERE: REQUEST FAILED: start=0&q=id:[100+TO+110]&qt=standard&rows=20&version=2.0:java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='3']
        [junit] xml response was: <?xml version="1.0" encoding="UTF-8"?>
        [junit] <response>
        [junit] <responseHeader><status>0</status><QTime>0</QTime></responseHeader><result name="response" numFound="0" start="0"/>
        [junit] </response>
        [junit]
        [junit] request was:start=0&q=id:[100+TO+110]&qt=standard&rows=20&version=2.0
        [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:378)
        [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:352)
        [junit] at org.apache.solr.handler.TestCSVLoader.testCommitWithin(TestCSVLoader.java:121)
        [junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        [junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        [junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        [junit] at java.lang.reflect.Method.invoke(Method.java:597)
        [junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
        [junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
        [junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
        [junit] at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
        [junit] at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48)
        [junit] at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
        [junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
        [junit] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
        [junit] at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:147)
        [junit] at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:50)
        [junit] at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
        [junit] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
        [junit] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
        [junit] at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
        [junit] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
        [junit] at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
        [junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
        [junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
        [junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
        [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
        [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
        [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:743)
        [junit]
        [junit] NOTE: reproduce with: ant test -Dtestcase=TestCSVLoader -Dtestmethod=testCommitWithin -Dtests.seed=-17a44f827c503e4f:5a853ada905dd3c8:-362930cca8744e9b
        [junit] NOTE: test params are: locale=sq_AL, timezone=Asia/Tashkent
        [junit] NOTE: all tests run in this JVM:
        [junit] [SolrInfoMBeanTest, TestSolrCoreProperties, DoubleMetaphoneFilterFactoryTest, TestArabicFilters, TestBulgarianStemFilterFactory, TestCzechStemFilterFactory, TestDictionaryCompoundWordTokenFilterFactory, TestGreekStemFilterFactory, TestHindiFilters, TestKeepFilterFactory, TestTurkishLowerCaseFilterFactory, TestJmxIntegration, TestLegacyMergeSchedulerPolicyConfig, TestPropInjectDefaults, TestCSVLoader]
        [junit] NOTE: Linux 2.6.32-71.29.1.el6.centos.plus.x86_64 amd64/Sun Microsystems Inc. 1.6.0_27 (64-bit)/cpus=4,threads=2,free=146206112,total=246153216
        [junit] ------------- ---------------- ---------------
        [junit] TEST org.apache.solr.handler.TestCSVLoader FAILED

        Show
        Shawn Heisey added a comment - I've also been seeing intermittent failures in TestCSVLoader, in both 3.4 and 3x. The nature of the failure is the same as on TestSqlEntityProcessorDelta, numFound shows a different value than what the test expects. If I run the following command over and over, sometimes it will fail, but mostly it will pass: ant test -Dtestcase=TestCSVLoader -Dtestmethod=testCommitWithin Here's one failure on lucene_solr_3_4: [junit] Testsuite: org.apache.solr.handler.TestCSVLoader [junit] Testcase: testCommitWithin(org.apache.solr.handler.TestCSVLoader): Caused an ERROR [junit] Exception during query [junit] java.lang.RuntimeException: Exception during query [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:385) [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:352) [junit] at org.apache.solr.handler.TestCSVLoader.testCommitWithin(TestCSVLoader.java:121) [junit] at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:147) [junit] at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:50) [junit] Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//* [@numFound='3'] [junit] xml response was: <?xml version="1.0" encoding="UTF-8"?> [junit] <response> [junit] <responseHeader><status>0</status><QTime>0</QTime></responseHeader><result name="response" numFound="0" start="0"/> [junit] </response> [junit] [junit] request was:start=0&q=id: [100+TO+110] &qt=standard&rows=20&version=2.0 [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:378) [junit] [junit] [junit] Tests run: 5, Failures: 0, Errors: 1, Time elapsed: 29.793 sec [junit] [junit] ------------- Standard Error ----------------- [junit] 2011-09-15 12:46:04.PD org.apache.solr.SolrTestCaseJ4 assertQ [junit] SEVERE: REQUEST FAILED: xpath=//* [@numFound='3'] [junit] xml response was: <?xml version="1.0" encoding="UTF-8"?> [junit] <response> [junit] <responseHeader><status>0</status><QTime>0</QTime></responseHeader><result name="response" numFound="0" start="0"/> [junit] </response> [junit] [junit] request was:start=0&q=id: [100+TO+110] &qt=standard&rows=20&version=2.0 [junit] 2011-09-15 12:46:04.PD org.apache.solr.common.SolrException log [junit] SEVERE: REQUEST FAILED: start=0&q=id: [100+TO+110] &qt=standard&rows=20&version=2.0:java.lang.RuntimeException: REQUEST FAILED: xpath=//* [@numFound='3'] [junit] xml response was: <?xml version="1.0" encoding="UTF-8"?> [junit] <response> [junit] <responseHeader><status>0</status><QTime>0</QTime></responseHeader><result name="response" numFound="0" start="0"/> [junit] </response> [junit] [junit] request was:start=0&q=id: [100+TO+110] &qt=standard&rows=20&version=2.0 [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:378) [junit] at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:352) [junit] at org.apache.solr.handler.TestCSVLoader.testCommitWithin(TestCSVLoader.java:121) [junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [junit] at java.lang.reflect.Method.invoke(Method.java:597) [junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) [junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) [junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) [junit] at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) [junit] at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) [junit] at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) [junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31) [junit] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) [junit] at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:147) [junit] at org.apache.lucene.util.LuceneTestCaseRunner.runChild(LuceneTestCaseRunner.java:50) [junit] at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) [junit] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) [junit] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) [junit] at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) [junit] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) [junit] at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) [junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31) [junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:236) [junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420) [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911) [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:743) [junit] [junit] NOTE: reproduce with: ant test -Dtestcase=TestCSVLoader -Dtestmethod=testCommitWithin -Dtests.seed=-17a44f827c503e4f:5a853ada905dd3c8:-362930cca8744e9b [junit] NOTE: test params are: locale=sq_AL, timezone=Asia/Tashkent [junit] NOTE: all tests run in this JVM: [junit] [SolrInfoMBeanTest, TestSolrCoreProperties, DoubleMetaphoneFilterFactoryTest, TestArabicFilters, TestBulgarianStemFilterFactory, TestCzechStemFilterFactory, TestDictionaryCompoundWordTokenFilterFactory, TestGreekStemFilterFactory, TestHindiFilters, TestKeepFilterFactory, TestTurkishLowerCaseFilterFactory, TestJmxIntegration, TestLegacyMergeSchedulerPolicyConfig, TestPropInjectDefaults, TestCSVLoader] [junit] NOTE: Linux 2.6.32-71.29.1.el6.centos.plus.x86_64 amd64/Sun Microsystems Inc. 1.6.0_27 (64-bit)/cpus=4,threads=2,free=146206112,total=246153216 [junit] ------------- ---------------- --------------- [junit] TEST org.apache.solr.handler.TestCSVLoader FAILED
        Hide
        Shawn Heisey added a comment -

        I've now tried it on a completely unrelated Debian system (Squeeze, ext4) with the same TestSqlEntityProcessorDelta failure. All packages on this system are from the standard Debian repositories, and include ant 1.8.1, which I remember reading isn't supported by the lucene/solr build system. I also tried to do it on a Debian Lenny system, but it's running ant 1.7.0 and won't run Solr's build.xml at all.

        Show
        Shawn Heisey added a comment - I've now tried it on a completely unrelated Debian system (Squeeze, ext4) with the same TestSqlEntityProcessorDelta failure. All packages on this system are from the standard Debian repositories, and include ant 1.8.1, which I remember reading isn't supported by the lucene/solr build system. I also tried to do it on a Debian Lenny system, but it's running ant 1.7.0 and won't run Solr's build.xml at all.
        Hide
        Hoss Man added a comment -

        Shawn: still no suggestion for you on why you're the only one getting failures with TestSqlEntityProcessorDelta, but as for this...

        I've also been seeing intermittent failures in TestCSVLoader, in both 3.4 and 3x.

        ...that is definitely unrelated, see SOLR-2540.

        Show
        Hoss Man added a comment - Shawn: still no suggestion for you on why you're the only one getting failures with TestSqlEntityProcessorDelta, but as for this... I've also been seeing intermittent failures in TestCSVLoader, in both 3.4 and 3x. ...that is definitely unrelated, see SOLR-2540 .
        Hide
        Robert Muir added a comment -

        3.4 -> 3.5

        Show
        Robert Muir added a comment - 3.4 -> 3.5
        Hide
        Shawn Heisey added a comment -

        I was looking at the test and SOLR-2551, the issue where it was created. It could be that I'm misreading that issue, but shouldn't it only fail to import on a delta? The code for testNonWritablePersistFile does a full import before it does the numFound check.

        Changing runFullImport to runDeltaImport makes the test pass for me.

        Have I got the wrong idea here?

        Show
        Shawn Heisey added a comment - I was looking at the test and SOLR-2551 , the issue where it was created. It could be that I'm misreading that issue, but shouldn't it only fail to import on a delta ? The code for testNonWritablePersistFile does a full import before it does the numFound check. Changing runFullImport to runDeltaImport makes the test pass for me. Have I got the wrong idea here?
        Hide
        Shawn Heisey added a comment -

        If I do have the right idea, then the rest of this paragraph applies, otherwise not: I have to wonder why the current test is passing for everyone but me. It seems as though it should be failing for everyone.

        I added a couple more lines, so now it tries a delta import, checks for numFound=0, then runs a full import and checks for numFound=1. Contrary to what I expected, the second part failed.

        Show
        Shawn Heisey added a comment - If I do have the right idea, then the rest of this paragraph applies, otherwise not: I have to wonder why the current test is passing for everyone but me. It seems as though it should be failing for everyone. I added a couple more lines, so now it tries a delta import, checks for numFound=0, then runs a full import and checks for numFound=1. Contrary to what I expected, the second part failed.
        Hide
        Shalin Shekhar Mangar added a comment -

        Shawn, the test does a full-import because that operation also writes the last import time to the dataimport.properties and a delta import is supposed to start from after that time. So, if dataimport.properties is not writable, a delta import will always do a full import regardless of whether a full import had succeeded before it. This is why the test makes sure that a full-import is failed if dataimport.properties is not writable and the data-config has configured the delta import related attributes.

        Show
        Shalin Shekhar Mangar added a comment - Shawn, the test does a full-import because that operation also writes the last import time to the dataimport.properties and a delta import is supposed to start from after that time. So, if dataimport.properties is not writable, a delta import will always do a full import regardless of whether a full import had succeeded before it. This is why the test makes sure that a full-import is failed if dataimport.properties is not writable and the data-config has configured the delta import related attributes.
        Hide
        Shawn Heisey added a comment -

        Shalin,

        Thanks. So the weird thing on my system is that the import is not only proceeding, it's succeeding, so there is a document in the index when it turns around and queries for id:1, so the test as-is fails for me.

        If I tell it to do a delta import rather than a full import, the test succeeds - no document is indexed. If I tell it to do a delta import, check for no documents, then do a full import and check for 1 document, the second part fails - the full import did not index anything.

        None of my test runs show the following exception in checkWritablePersistFile. On systems where the test passes, is it thrown?

        throw new DataImportHandlerException(SEVERE, persistFile.getAbsolutePath() +
        " is not writable. Delta imports are supported by data config but will not work.");

        There's nothing particularly unusual about this setup. It's 64-bit CentOS 6, ext4 over LVM on a Dell server with hardware RAID1, running Oracle Java 1.6.0_27. Java was installed using the method on this page, with the nosrc rpm specific to version _27, not the _26 one on the page:
        http://www.city-fan.org/tips/SunJava6OnFedora

        My best guess (on the unmodified test) is that when checkWritablePersistFile (called from doFullImport) runs the isWritable() check, it is being told that the file is writable, so the full import proceeds. I can't see any reason for the check to work correctly on delta import but not work on full import.

        My first thought is thread locking/timing problems in the test code, but I don't know how to look for that, and I know the build.xml for DIH tests is configured to not run tests in parallel. Second thought if that's not the problem is that it is a bug in the OS, Java, or the OS/Java combination. It fails on CentOS5/1.6.0_26 on NFS and ext3. It fails on CentOS6/1.6.0_27 on NFS and ext4. It fails on Debian6/1.6.0_26 on ext4. Due to ongoing work that can't be interrupted to remake the platform, I can't easily try any other combinations.

        Show
        Shawn Heisey added a comment - Shalin, Thanks. So the weird thing on my system is that the import is not only proceeding, it's succeeding, so there is a document in the index when it turns around and queries for id:1, so the test as-is fails for me. If I tell it to do a delta import rather than a full import, the test succeeds - no document is indexed. If I tell it to do a delta import, check for no documents, then do a full import and check for 1 document, the second part fails - the full import did not index anything. None of my test runs show the following exception in checkWritablePersistFile. On systems where the test passes, is it thrown? throw new DataImportHandlerException(SEVERE, persistFile.getAbsolutePath() + " is not writable. Delta imports are supported by data config but will not work."); There's nothing particularly unusual about this setup. It's 64-bit CentOS 6, ext4 over LVM on a Dell server with hardware RAID1, running Oracle Java 1.6.0_27. Java was installed using the method on this page, with the nosrc rpm specific to version _27, not the _26 one on the page: http://www.city-fan.org/tips/SunJava6OnFedora My best guess (on the unmodified test) is that when checkWritablePersistFile (called from doFullImport) runs the isWritable() check, it is being told that the file is writable, so the full import proceeds. I can't see any reason for the check to work correctly on delta import but not work on full import. My first thought is thread locking/timing problems in the test code, but I don't know how to look for that, and I know the build.xml for DIH tests is configured to not run tests in parallel. Second thought if that's not the problem is that it is a bug in the OS, Java, or the OS/Java combination. It fails on CentOS5/1.6.0_26 on NFS and ext3. It fails on CentOS6/1.6.0_27 on NFS and ext4. It fails on Debian6/1.6.0_26 on ext4. Due to ongoing work that can't be interrupted to remake the platform, I can't easily try any other combinations.
        Hide
        Shawn Heisey added a comment -

        By adding print statements to the Solr and test code, I was able to determine that canWrite() is always returning true.

        As a further test, I wrote the following code:

        import java.io.*;
        
        public class Main
        {
                public static void main(String[] args)
                {
                        File f = new File("testfile");
                        File g = new File(".");
                        System.out.println("writable: " + f.canWrite());
                        f.setReadOnly();
                        System.out.println("writable: " + f.canWrite());
                        g.setReadOnly();
                        System.out.println("writable: " + f.canWrite());
                }
        }
        

        What this does is check canWrite on the file, then change the file to read only, then change the current directory to read only, printing the state of canWrite() after each step.

        I created a directory /tmp/testfile (0x755) and created a file in that directory called testfile (0x644). While in /tmp/testfile, I ran the above program. When it's done both the directory and the file have no write permissions, with this output:

        writable: true
        writable: true
        writable: true

        Running it multiple times produces the same output. This is looking to me like a bug in java, one that seems to have been there for quite a while. I got the same results on our production webserver (CentOS5 with java 1.6.0_14).

        Show
        Shawn Heisey added a comment - By adding print statements to the Solr and test code, I was able to determine that canWrite() is always returning true. As a further test, I wrote the following code: import java.io.*; public class Main { public static void main(String[] args) { File f = new File("testfile"); File g = new File("."); System.out.println("writable: " + f.canWrite()); f.setReadOnly(); System.out.println("writable: " + f.canWrite()); g.setReadOnly(); System.out.println("writable: " + f.canWrite()); } } What this does is check canWrite on the file, then change the file to read only, then change the current directory to read only, printing the state of canWrite() after each step. I created a directory /tmp/testfile (0x755) and created a file in that directory called testfile (0x644). While in /tmp/testfile, I ran the above program. When it's done both the directory and the file have no write permissions, with this output: writable: true writable: true writable: true Running it multiple times produces the same output. This is looking to me like a bug in java, one that seems to have been there for quite a while. I got the same results on our production webserver (CentOS5 with java 1.6.0_14).
        Hide
        Shawn Heisey added a comment -

        On Windows, it behaves as expected:

        C:\Users\sheisey\Downloads\testfile>java Main
        writable: true
        writable: false
        writable: false

        C:\Users\sheisey\Downloads\testfile>java -version
        java version "1.6.0_27"
        Java(TM) SE Runtime Environment (build 1.6.0_27-b07)
        Java HotSpot(TM) 64-Bit Server VM (build 20.2-b06, mixed mode)

        Show
        Shawn Heisey added a comment - On Windows, it behaves as expected: C:\Users\sheisey\Downloads\testfile>java Main writable: true writable: false writable: false C:\Users\sheisey\Downloads\testfile>java -version java version "1.6.0_27" Java(TM) SE Runtime Environment (build 1.6.0_27-b07) Java HotSpot(TM) 64-Bit Server VM (build 20.2-b06, mixed mode)
        Hide
        Shawn Heisey added a comment -

        I wondered how this problem didn't show up for me before now, so I checked something. The canWrite method shows up in the solr source in exactly two places:

        [root@bigindy5 solr]# grep -rl canWrite . | grep "java$"
        ./core/src/java/org/apache/solr/handler/SnapShooter.java
        ./contrib/dataimporthandler/src/java/org/apache/solr/handler/dataimport/DataImporter.java

        It's slightly more prevalent on the lucene side of the house:

        [root@bigindy5 lucene]# grep -rl canWrite . | grep "java$"
        ./contrib/spellchecker/src/java/org/apache/lucene/search/suggest/tst/TSTLookup.java
        ./contrib/spellchecker/src/java/org/apache/lucene/search/suggest/jaspell/JaspellLookup.java
        ./contrib/spellchecker/src/java/org/apache/lucene/search/suggest/fst/FSTLookup.java
        ./contrib/facet/src/java/org/apache/lucene/facet/search/TotalFacetCountsCache.java

        Show
        Shawn Heisey added a comment - I wondered how this problem didn't show up for me before now, so I checked something. The canWrite method shows up in the solr source in exactly two places: [root@bigindy5 solr] # grep -rl canWrite . | grep "java$" ./core/src/java/org/apache/solr/handler/SnapShooter.java ./contrib/dataimporthandler/src/java/org/apache/solr/handler/dataimport/DataImporter.java It's slightly more prevalent on the lucene side of the house: [root@bigindy5 lucene] # grep -rl canWrite . | grep "java$" ./contrib/spellchecker/src/java/org/apache/lucene/search/suggest/tst/TSTLookup.java ./contrib/spellchecker/src/java/org/apache/lucene/search/suggest/jaspell/JaspellLookup.java ./contrib/spellchecker/src/java/org/apache/lucene/search/suggest/fst/FSTLookup.java ./contrib/facet/src/java/org/apache/lucene/facet/search/TotalFacetCountsCache.java
        Hide
        Shawn Heisey added a comment -

        One of my co-workers has a Gentoo box with 2.6.38. Unlike my CentOS and Debian machines, this bug is not there:

        apalmer@toro /tmp/testfile $ java -version
        java version "1.6.0_26"
        Java(TM) SE Runtime Environment (build 1.6.0_26-b03)
        Java HotSpot(TM) 64-Bit Server VM (build 20.1-b02, mixed mode)

        apalmer@toro /tmp/testfile $ java Main
        writable: true
        writable: false
        writable: false

        Show
        Shawn Heisey added a comment - One of my co-workers has a Gentoo box with 2.6.38. Unlike my CentOS and Debian machines, this bug is not there: apalmer@toro /tmp/testfile $ java -version java version "1.6.0_26" Java(TM) SE Runtime Environment (build 1.6.0_26-b03) Java HotSpot(TM) 64-Bit Server VM (build 20.1-b02, mixed mode) apalmer@toro /tmp/testfile $ java Main writable: true writable: false writable: false
        Hide
        Shawn Heisey added a comment -

        My co-worker figured out the problem. Running it as root overrides the read-only permission. Tried it again as a nonprivileged user and everything is fine. Would it be difficult for "ant test" to see a username of root or a uid of 0? If a test fails and they are root/0, perhaps a warning could be issued asking them to try again with a nonprivileged user.

        Show
        Shawn Heisey added a comment - My co-worker figured out the problem. Running it as root overrides the read-only permission. Tried it again as a nonprivileged user and everything is fine. Would it be difficult for "ant test" to see a username of root or a uid of 0? If a test fails and they are root/0, perhaps a warning could be issued asking them to try again with a nonprivileged user.
        Hide
        Hoss Man added a comment -

        Shawn: awesome that you finally figured out the problem – never would have ocured to me you were running tests as root.

        i actually want to re-open this and make the test catch this.

        similar to how i made the test "assume" the setReadOnly call worked, i want the test to "assume" !isWritable so you don't get false failures here.

        Show
        Hoss Man added a comment - Shawn: awesome that you finally figured out the problem – never would have ocured to me you were running tests as root. i actually want to re-open this and make the test catch this. similar to how i made the test "assume" the setReadOnly call worked, i want the test to "assume" !isWritable so you don't get false failures here.
        Hide
        Hoss Man added a comment -

        I've committed additional "assume" statements to the test so that we not only verify setReadonly succeeds, but subsequent calls to canWrite fail. this should ensure that people running as root (or on esoteric filesystems that don't support read only files) don't see false failures.

        Show
        Hoss Man added a comment - I've committed additional "assume" statements to the test so that we not only verify setReadonly succeeds, but subsequent calls to canWrite fail. this should ensure that people running as root (or on esoteric filesystems that don't support read only files) don't see false failures.
        Hide
        Uwe Schindler added a comment -

        Bulk close after 3.5 is released

        Show
        Uwe Schindler added a comment - Bulk close after 3.5 is released

          People

          • Assignee:
            Hoss Man
            Reporter:
            Shawn Heisey
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development