You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/11/08 17:03:32 UTC

[JENKINS] Lucene-Solr-4.x-Linux (64bit/ibm-j9-jdk6) - Build # 8132 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/8132/
Java: 64bit/ibm-j9-jdk6 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}

2 tests failed.
REGRESSION:  org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testChildEntities

Error Message:
Exception during query

Stack Trace:
java.lang.RuntimeException: Exception during query
	at __randomizedtesting.SeedInfo.seed([2100A32888E1B6E:8D73E5D6B30706ED]:0)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:637)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:604)
	at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.withChildEntities(AbstractSqlEntityProcessorTestCase.java:225)
	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testChildEntities(TestSqlEntityProcessorDelta.java:82)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
	at java.lang.reflect.Method.invoke(Method.java:611)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:738)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//doc/str[@name='COUNTRY_NAME_s']='MODIFIED Nauru'
	xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="q">COUNTRY_CODES_mult_s:NR</str><str name="start">0</str><str name="qt">standard</str><str name="version">2.2</str><str name="rows">20</str></lst></lst><result name="response" numFound="2" start="0"><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Michael</str></arr><str name="id">3</str><str name="COUNTRY_NAME_s">Nauru</str><str name="COUNTRY_CODE_s">NR</str><str name="countryAdded_s">country_added</str><date name="timestamp">2013-11-08T16:03:07.595Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Samantha</str></arr><str name="id">20</str><str name="COUNTRY_NAME_s">Nauru</str><str name="COUNTRY_CODE_s">NR</str><str name="countryAdded_s">country_added</str><date name="timestamp">2013-11-08T16:03:07.595Z</date></doc></result>
</response>

	request was:q=COUNTRY_CODES_mult_s:NR&start=0&qt=standard&version=2.2&rows=20
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:630)
	... 43 more


REGRESSION:  org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testWithSimpleTransformer

Error Message:
Exception during query

Stack Trace:
java.lang.RuntimeException: Exception during query
	at __randomizedtesting.SeedInfo.seed([2100A32888E1B6E:6D5422D852587763]:0)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:637)
	at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.simpleTransform(AbstractSqlEntityProcessorTestCase.java:116)
	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testWithSimpleTransformer(TestSqlEntityProcessorDelta.java:58)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
	at java.lang.reflect.Method.invoke(Method.java:611)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:738)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='14']
	xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="q">AddAColumn_s:Added</str><str name="start">0</str><str name="qt">standard</str><str name="version">2.2</str><str name="rows">20</str></lst></lst><result name="response" numFound="20" start="0"><doc><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Jacob</str></arr><str name="id">1</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Ethan</str></arr><str name="id">2</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Michael</str></arr><str name="id">3</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NP</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Jayden</str></arr><str name="id">4</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NO</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>William</str></arr><str name="id">5</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Alexander</str></arr><str name="id">6</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Noah</str></arr><str name="id">7</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Daniel</str></arr><str name="id">8</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Aiden</str></arr><str name="id">9</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Anthony</str></arr><str name="id">10</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Emma</str></arr><str name="id">11</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Grace</str></arr><str name="id">12</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Hailey</str></arr><str name="id">13</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Isabella</str></arr><str name="id">14</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Lily</str></arr><str name="id">15</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NC</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Madison</str></arr><str name="id">16</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NA</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Mia</str></arr><str name="id">17</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Natalie</str></arr><str name="id">18</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Olivia</str></arr><str name="id">19</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Samantha</str></arr><str name="id">20</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc></result>
</response>

	request was:q=AddAColumn_s:Added&start=0&qt=standard&version=2.2&rows=20
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:630)
	... 42 more




Build Log:
[...truncated 13324 lines...]
   [junit4] Suite: org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
   [junit4]   2> 65162 T199 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146
   [junit4]   2> 65163 T199 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/collection1/'
   [junit4]   2> 65206 T199 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 65240 T199 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
   [junit4]   2> 65241 T199 oass.IndexSchema.readSchema Reading Solr Schema from dataimport-schema.xml
   [junit4]   2> 65253 T199 oass.IndexSchema.readSchema [null] Schema name=dih_test
   [junit4]   2> 65293 T199 oass.IndexSchema.readSchema default search field in schema is desc
   [junit4]   2> 65295 T199 oass.IndexSchema.readSchema query parser default operator is OR
   [junit4]   2> 65296 T199 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 65297 T199 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 65298 T199 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr
   [junit4]   2> 65298 T199 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/'
   [junit4]   2> 65316 T199 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 65317 T199 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr
   [junit4]   2> 65317 T199 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/'
   [junit4]   2> 65366 T199 oasc.CoreContainer.<init> New CoreContainer 299045331
   [junit4]   2> 65367 T199 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/]
   [junit4]   2> 65368 T199 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 65369 T199 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 65369 T199 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 65370 T199 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 65370 T199 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 65371 T199 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 65371 T199 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 65372 T199 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 65372 T199 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 65374 T199 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 65374 T199 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 65379 T201 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/collection1
   [junit4]   2> 65380 T201 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/collection1/'
   [junit4]   2> 65430 T201 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 65476 T201 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
   [junit4]   2> 65478 T201 oass.IndexSchema.readSchema Reading Solr Schema from dataimport-schema.xml
   [junit4]   2> 65483 T201 oass.IndexSchema.readSchema [collection1] Schema name=dih_test
   [junit4]   2> 65529 T201 oass.IndexSchema.readSchema default search field in schema is desc
   [junit4]   2> 65530 T201 oass.IndexSchema.readSchema query parser default operator is OR
   [junit4]   2> 65532 T201 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 65533 T201 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 65533 T201 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146/
   [junit4]   2> 65534 T201 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 65535 T201 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=solr,start=0,rows=10}, {q=rocks,start=0,rows=10}, {q=static newSearcher warming query from solrconfig.xml}]}
   [junit4]   2> 65535 T201 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
   [junit4]   2> 65536 T201 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146
   [junit4]   2> 65536 T201 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146/index/
   [junit4]   2> 65537 T201 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146/index' doesn't exist. Creating new index...
   [junit4]   2> 65538 T201 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146/index
   [junit4]   2> 65540 T201 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_1,generation=1}
   [junit4]   2> 65541 T201 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 65543 T201 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "" (default)
   [junit4]   2> 65543 T201 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "" (default)
   [junit4]   2> 65544 T201 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 65544 T201 oasc.RequestHandlers.initHandlersFromConfig created /dataimport: org.apache.solr.handler.dataimport.DataImportHandler
   [junit4]   2> 65545 T201 oasc.RequestHandlers.initHandlersFromConfig created /search: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 65545 T201 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 65547 T201 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 65549 T201 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 65550 T201 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 65552 T201 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_1,generation=1}
   [junit4]   2> 65552 T201 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 65553 T201 oass.SolrIndexSearcher.<init> Opening Searcher@35af35af main
   [junit4]   2> 65554 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@35af35af main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 65554 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 65554 T201 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 65555 T202 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@35af35af main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 65557 T199 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 65568 T199 oas.SolrTestCaseJ4.setUp ###Starting testChildEntities
   [junit4]   2> ASYNC  NEW_CORE C62 name=collection1 org.apache.solr.core.SolrCore@1bf71bf7
   [junit4]   2> 65577 T199 C62 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 65579 T199 C62 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 4
   [junit4]   2> 65592 T199 C62 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 65594 T199 C62 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_2,generation=2}
   [junit4]   2> 65594 T199 C62 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 65595 T199 C62 oass.SolrIndexSearcher.<init> Opening Searcher@36503650 main
   [junit4]   2> 65596 T199 C62 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 65596 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@36503650 main{StandardDirectoryReader(segments_2:2:nrt)}
   [junit4]   2> 65598 T202 C62 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=1 
   [junit4]   2> 65599 T202 C62 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=1 
   [junit4]   2> 65599 T202 C62 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 65600 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 65600 T202 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36503650 main{StandardDirectoryReader(segments_2:2:nrt)}
   [junit4]   2> 65601 T199 C62 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 11
   [junit4]   2> 65615 T199 C62 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
   [junit4]   2> 65616 T199 C62 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
   [junit4]   2> 65617 T199 C62 oashd.DataImporter.doFullImport Starting Full Import
   [junit4]   2> 65619 T199 C62 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
   [junit4]   2> 65620 T199 C62 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 65621 T199 C62 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
   [junit4]   2> 65622 T199 C62 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
   [junit4]   2> 65624 T199 C62 oashd.JdbcDataSource$1.call Creating a connection for entity Countries with URL: jdbc:hsqldb:mem:.
   [junit4]   2> 65625 T199 C62 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
   [junit4]   2> 65641 T199 C62 oashd.DocBuilder.finish Import completed successfully
   [junit4]   2> 65642 T199 C62 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 65648 T199 C62 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_3,generation=3}
   [junit4]   2> 65649 T199 C62 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 65651 T199 C62 oass.SolrIndexSearcher.<init> Opening Searcher@77817781 main
   [junit4]   2> 65652 T199 C62 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 65653 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@77817781 main{StandardDirectoryReader(segments_3:5:nrt _0(4.6):c20)}
   [junit4]   2> 65655 T202 C62 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=1 
   [junit4]   2> 65655 T202 C62 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 65656 T202 C62 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 65656 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 65657 T202 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@77817781 main{StandardDirectoryReader(segments_3:5:nrt _0(4.6):c20)}
   [junit4]   2> 65658 T199 C62 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
   [junit4]   2> 65660 T199 C62 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
   [junit4]   2> 65660 T199 C62 oashd.DocBuilder.execute Time taken = 0:0:0.41
   [junit4]   2> 65661 T199 C62 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={commit=true&synchronous=true&clean=true&command=full-import&indent=true&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"./test3118462244475305042tmp"+filename%3D"the.properties"+/>%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.People.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a<entity+name%3D"Countries"+pk%3D"Countries.CODE"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+newColumnName%3D"countryAdded_s"+newColumnValue%3D"country_added"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+CODE,+COUNTRY_NAME+FROM+COUNTRIES+WHERE+DELETED+!%3D+'Y'+AND+CODE%3D'${People.COUNTRY_CODE}'+"+>+%0a<field+column%3D"CODE"+name%3D"COUNTRY_CODE_s"+/>+%0a<field+column%3D"COUNTRY_NAME"+name%3D"COUNTRY_NAME_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 49
   [junit4]   2> 65664 T199 C62 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=*:*&start=0&qt=standard&version=2.2&rows=20} hits=20 status=0 QTime=0 
   [junit4]   2> 65670 T199 C62 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=AddAColumn_s:Added&start=0&qt=standard&version=2.2&rows=20} hits=20 status=0 QTime=1 
   [junit4]   2> ASYNC  NEW_CORE C63 name=collection1 org.apache.solr.core.SolrCore@1bf71bf7
   [junit4]   2> 65686 T199 C63 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=NAME_mult_s:Jayden&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=0 
   [junit4]   2> 65693 T199 C63 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=COUNTRY_CODES_mult_s:NR&start=0&qt=standard&version=2.2&rows=20} hits=2 status=0 QTime=0 
   [junit4]   2> 65696 T199 C63 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=countryAdded_s:country_added&start=0&qt=standard&version=2.2&rows=20} hits=20 status=0 QTime=1 
   [junit4]   2> 65698 T199 C63 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
   [junit4]   2> 65699 T199 C63 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
   [junit4]   2> 65700 T199 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
   [junit4]   2> 65706 T199 C63 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
   [junit4]   2> 65707 T199 C63 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
   [junit4]   2> 65708 T199 C63 oashd.DataImporter.doDeltaImport Starting Delta Import
   [junit4]   2> 65709 T199 C63 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
   [junit4]   2> 65711 T199 C63 oashd.DocBuilder.doDelta Starting delta collection.
   [junit4]   2> 65712 T199 C63 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: Countries
   [junit4]   2> 65712 T199 C63 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: Countries rows obtained : 0
   [junit4]   2> 65713 T199 C63 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: Countries rows obtained : 0
   [junit4]   2> 65713 T199 C63 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: Countries
   [junit4]   2> 65714 T199 C63 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
   [junit4]   2> 65715 T199 C63 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
   [junit4]   2> 65716 T199 C63 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
   [junit4]   2> 65780 T199 C63 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 0
   [junit4]   2> 65781 T199 C63 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
   [junit4]   2> 65782 T199 C63 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
   [junit4]   2> 65783 T199 C63 oashd.DocBuilder.doDelta Delta Import completed successfully
   [junit4]   2> 65784 T199 C63 oashd.DocBuilder.execute Time taken = 0:0:0.74
   [junit4]   2> 65784 T199 C63 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={commit=true&synchronous=true&clean=false&command=delta-import&indent=true&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"./test3118462244475305042tmp"+filename%3D"the.properties"+/>%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"People.ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.People.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a<entity+name%3D"Countries"+pk%3D"CODE"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+newColumnName%3D"countryAdded_s"+newColumnValue%3D"country_added"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+CODE,+COUNTRY_NAME+FROM+COUNTRIES+WHERE+DELETED+!%3D+'Y'+AND+CODE%3D'${People.COUNTRY_CODE}'+"+>+%0a<field+column%3D"CODE"+name%3D"COUNTRY_CODE_s"+/>+%0a<field+column%3D"COUNTRY_NAME"+name%3D"COUNTRY_NAME_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a} {} 0 81
   [junit4]   2> 65787 T199 C63 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=*:*&start=0&qt=standard&version=2.2&rows=20} hits=20 status=0 QTime=1 
   [junit4]   2> 65790 T199 C63 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=NAME_mult_s:Jayden&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=0 
   [junit4]   2> 65795 T199 C63 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=COUNTRY_CODES_mult_s:NR&start=0&qt=standard&version=2.2&rows=20} hits=2 status=0 QTime=1 
   [junit4]   2> 65797 T199 oas.SolrTestCaseJ4.assertQ ERROR REQUEST FAILED: xpath=//doc/str[@name='COUNTRY_NAME_s']='MODIFIED Nauru'
   [junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]   2> 	<response>
   [junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="q">COUNTRY_CODES_mult_s:NR</str><str name="start">0</str><str name="qt">standard</str><str name="version">2.2</str><str name="rows">20</str></lst></lst><result name="response" numFound="2" start="0"><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Michael</str></arr><str name="id">3</str><str name="COUNTRY_NAME_s">Nauru</str><str name="COUNTRY_CODE_s">NR</str><str name="countryAdded_s">country_added</str><date name="timestamp">2013-11-08T16:03:07.595Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Samantha</str></arr><str name="id">20</str><str name="COUNTRY_NAME_s">Nauru</str><str name="COUNTRY_CODE_s">NR</str><str name="countryAdded_s">country_added</str><date name="timestamp">2013-11-08T16:03:07.595Z</date></doc></result>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:q=COUNTRY_CODES_mult_s:NR&start=0&qt=standard&version=2.2&rows=20
   [junit4]   2> 65798 T199 oasc.SolrException.log ERROR REQUEST FAILED: q=COUNTRY_CODES_mult_s:NR&start=0&qt=standard&version=2.2&rows=20:java.lang.RuntimeException: REQUEST FAILED: xpath=//doc/str[@name='COUNTRY_NAME_s']='MODIFIED Nauru'
   [junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]   2> 	<response>
   [junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="q">COUNTRY_CODES_mult_s:NR</str><str name="start">0</str><str name="qt">standard</str><str name="version">2.2</str><str name="rows">20</str></lst></lst><result name="response" numFound="2" start="0"><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Michael</str></arr><str name="id">3</str><str name="COUNTRY_NAME_s">Nauru</str><str name="COUNTRY_CODE_s">NR</str><str name="countryAdded_s">country_added</str><date name="timestamp">2013-11-08T16:03:07.595Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Samantha</str></arr><str name="id">20</str><str name="COUNTRY_NAME_s">Nauru</str><str name="COUNTRY_CODE_s">NR</str><str name="countryAdded_s">country_added</str><date name="timestamp">2013-11-08T16:03:07.595Z</date></doc></result>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:q=COUNTRY_CODES_mult_s:NR&start=0&qt=standard&version=2.2&rows=20
   [junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:630)
   [junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:604)
   [junit4]   2> 		at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.withChildEntities(AbstractSqlEntityProcessorTestCase.java:225)
   [junit4]   2> 		at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testChildEntities(TestSqlEntityProcessorDelta.java:82)
   [junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
   [junit4]   2> 		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   [junit4]   2> 		at java.lang.reflect.Method.invoke(Method.java:611)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
   [junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:738)
   [junit4]   2> 	
   [junit4]   2> 65800 T199 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/solr/collection1/conf/dataimport.properties
   [junit4]   2> 65801 T199 oas.SolrTestCaseJ4.tearDown ###Ending testChildEntities
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSqlEntityProcessorDelta -Dtests.method=testChildEntities -Dtests.seed=2100A32888E1B6E -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ja_JP_JP -Dtests.timezone=Asia/Ashgabat -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.27s | TestSqlEntityProcessorDelta.testChildEntities <<<
   [junit4]    > Throwable #1: java.lang.RuntimeException: Exception during query
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([2100A32888E1B6E:8D73E5D6B30706ED]:0)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:637)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:604)
   [junit4]    > 	at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.withChildEntities(AbstractSqlEntityProcessorTestCase.java:225)
   [junit4]    > 	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testChildEntities(TestSqlEntityProcessorDelta.java:82)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:738)
   [junit4]    > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//doc/str[@name='COUNTRY_NAME_s']='MODIFIED Nauru'
   [junit4]    > 	xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]    > <response>
   [junit4]    > <lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="q">COUNTRY_CODES_mult_s:NR</str><str name="start">0</str><str name="qt">standard</str><str name="version">2.2</str><str name="rows">20</str></lst></lst><result name="response" numFound="2" start="0"><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Michael</str></arr><str name="id">3</str><str name="COUNTRY_NAME_s">Nauru</str><str name="COUNTRY_CODE_s">NR</str><str name="countryAdded_s">country_added</str><date name="timestamp">2013-11-08T16:03:07.595Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Samantha</str></arr><str name="id">20</str><str name="COUNTRY_NAME_s">Nauru</str><str name="COUNTRY_CODE_s">NR</str><str name="countryAdded_s">country_added</str><date name="timestamp">2013-11-08T16:03:07.595Z</date></doc></result>
   [junit4]    > </response>
   [junit4]    > 	request was:q=COUNTRY_CODES_mult_s:NR&start=0&qt=standard&version=2.2&rows=20
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:630)
   [junit4]    > 	... 43 more
   [junit4]   2> 65835 T199 oas.SolrTestCaseJ4.setUp ###Starting testWithSimpleTransformer
   [junit4]   2> ASYNC  NEW_CORE C64 name=collection1 org.apache.solr.core.SolrCore@1bf71bf7
   [junit4]   2> 65851 T199 C64 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 65852 T199 C64 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 4
   [junit4]   2> 65858 T199 C64 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 65860 T199 C64 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_4,generation=4}
   [junit4]   2> 65860 T199 C64 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 65861 T199 C64 oass.SolrIndexSearcher.<init> Opening Searcher@1f1f1f1f main
   [junit4]   2> 65862 T199 C64 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 65863 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1f1f1f1f main{StandardDirectoryReader(segments_4:6:nrt)}
   [junit4]   2> 65864 T202 C64 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 65865 T202 C64 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 65866 T202 C64 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=1 
   [junit4]   2> 65866 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 65867 T202 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f1f1f1f main{StandardDirectoryReader(segments_4:6:nrt)}
   [junit4]   2> 65867 T199 C64 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 10
   [junit4]   2> 65880 T199 C64 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
   [junit4]   2> 65881 T199 C64 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
   [junit4]   2> 65883 T199 C64 oashd.DataImporter.doFullImport Starting Full Import
   [junit4]   2> 65884 T199 C64 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
   [junit4]   2> 65885 T199 C64 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 65887 T199 C64 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
   [junit4]   2> 65888 T199 C64 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
   [junit4]   2> 65896 T199 C64 oashd.DocBuilder.finish Import completed successfully
   [junit4]   2> 65897 T199 C64 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 65902 T199 C64 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_5,generation=5}
   [junit4]   2> 65902 T199 C64 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 65904 T199 C64 oass.SolrIndexSearcher.<init> Opening Searcher@693b693b main
   [junit4]   2> 65905 T199 C64 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 65907 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@693b693b main{StandardDirectoryReader(segments_5:9:nrt _1(4.6):c20)}
   [junit4]   2> 65907 T202 C64 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 65908 T202 C64 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 65909 T202 C64 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 65910 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 65910 T202 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@693b693b main{StandardDirectoryReader(segments_5:9:nrt _1(4.6):c20)}
   [junit4]   2> 65911 T199 C64 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
   [junit4]   2> 65912 T199 C64 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
   [junit4]   2> 65913 T199 C64 oashd.DocBuilder.execute Time taken = 0:0:0.28
   [junit4]   2> 65913 T199 C64 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={commit=true&synchronous=true&clean=true&command=full-import&indent=true&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"./test5847345917521523757tmp"+filename%3D"the.properties"+/>%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"People.ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.People.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 35
   [junit4]   2> 65916 T199 C64 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=AddAColumn_s:Added&start=0&qt=standard&version=2.2&rows=20} hits=20 status=0 QTime=1 
   [junit4]   2> 65920 T199 C64 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
   [junit4]   2> 65921 T199 C64 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
   [junit4]   2> 65922 T199 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
   [junit4]   2> 65927 T199 C64 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
   [junit4]   2> 65928 T199 C64 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
   [junit4]   2> ASYNC  NEW_CORE C65 name=collection1 org.apache.solr.core.SolrCore@1bf71bf7
   [junit4]   2> 65938 T199 C65 oashd.DataImporter.doDeltaImport Starting Delta Import
   [junit4]   2> 65939 T199 C65 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
   [junit4]   2> 65941 T199 C65 oashd.DocBuilder.doDelta Starting delta collection.
   [junit4]   2> 65942 T199 C65 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
   [junit4]   2> 65943 T199 C65 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
   [junit4]   2> 65944 T199 C65 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
   [junit4]   2> 65971 T199 C65 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 0
   [junit4]   2> 65973 T199 C65 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
   [junit4]   2> 65974 T199 C65 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
   [junit4]   2> 65975 T199 C65 oashd.DocBuilder.doDelta Delta Import completed successfully
   [junit4]   2> 65976 T199 C65 oashd.DocBuilder.execute Time taken = 0:0:0.36
   [junit4]   2> 65977 T199 C65 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={commit=true&synchronous=true&clean=false&command=delta-import&indent=true&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"./test5847345917521523757tmp"+filename%3D"the.properties"+/>%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.People.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a} {} 0 52
   [junit4]   2> 65979 T199 C65 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=AddAColumn_s:Added&start=0&qt=standard&version=2.2&rows=20} hits=20 status=0 QTime=1 
   [junit4]   2> 65982 T199 oas.SolrTestCaseJ4.assertQ ERROR REQUEST FAILED: xpath=//*[@numFound='14']
   [junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]   2> 	<response>
   [junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="q">AddAColumn_s:Added</str><str name="start">0</str><str name="qt">standard</str><str name="version">2.2</str><str name="rows">20</str></lst></lst><result name="response" numFound="20" start="0"><doc><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Jacob</str></arr><str name="id">1</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Ethan</str></arr><str name="id">2</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Michael</str></arr><str name="id">3</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NP</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Jayden</str></arr><str name="id">4</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NO</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>William</str></arr><str name="id">5</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Alexander</str></arr><str name="id">6</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Noah</str></arr><str name="id">7</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Daniel</str></arr><str name="id">8</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Aiden</str></arr><str name="id">9</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Anthony</str></arr><str name="id">10</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Emma</str></arr><str name="id">11</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Grace</str></arr><str name="id">12</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Hailey</str></arr><str name="id">13</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Isabella</str></arr><str name="id">14</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Lily</str></arr><str name="id">15</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NC</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Madison</str></arr><str name="id">16</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NA</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Mia</str></arr><str name="id">17</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Natalie</str></arr><str name="id">18</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Olivia</str></arr><str name="id">19</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Samantha</str></arr><str name="id">20</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc></result>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:q=AddAColumn_s:Added&start=0&qt=standard&version=2.2&rows=20
   [junit4]   2> 65984 T199 oasc.SolrException.log ERROR REQUEST FAILED: q=AddAColumn_s:Added&start=0&qt=standard&version=2.2&rows=20:java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='14']
   [junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]   2> 	<response>
   [junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="q">AddAColumn_s:Added</str><str name="start">0</str><str name="qt">standard</str><str name="version">2.2</str><str name="rows">20</str></lst></lst><result name="response" numFound="20" start="0"><doc><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Jacob</str></arr><str name="id">1</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Ethan</str></arr><str name="id">2</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Michael</str></arr><str name="id">3</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NP</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Jayden</str></arr><str name="id">4</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NO</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>William</str></arr><str name="id">5</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Alexander</str></arr><str name="id">6</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Noah</str></arr><str name="id">7</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Daniel</str></arr><str name="id">8</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Aiden</str></arr><str name="id">9</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Anthony</str></arr><str name="id">10</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Emma</str></arr><str name="id">11</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Grace</str></arr><str name="id">12</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Hailey</str></arr><str name="id">13</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Isabella</str></arr><str name="id">14</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Lily</str></arr><str name="id">15</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NC</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Madison</str></arr><str name="id">16</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NA</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Mia</str></arr><str name="id">17</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Natalie</str></arr><str name="id">18</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Olivia</str></arr><str name="id">19</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Samantha</str></arr><str name="id">20</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc></result>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:q=AddAColumn_s:Added&start=0&qt=standard&version=2.2&rows=20
   [junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:630)
   [junit4]   2> 		at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.simpleTransform(AbstractSqlEntityProcessorTestCase.java:116)
   [junit4]   2> 		at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testWithSimpleTransformer(TestSqlEntityProcessorDelta.java:58)
   [junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
   [junit4]   2> 		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   [junit4]   2> 		at java.lang.reflect.Method.invoke(Method.java:611)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
   [junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:738)
   [junit4]   2> 	
   [junit4]   2> 65986 T199 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/solr/collection1/conf/dataimport.properties
   [junit4]   2> 65987 T199 oas.SolrTestCaseJ4.tearDown ###Ending testWithSimpleTransformer
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSqlEntityProcessorDelta -Dtests.method=testWithSimpleTransformer -Dtests.seed=2100A32888E1B6E -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ja_JP_JP -Dtests.timezone=Asia/Ashgabat -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.18s | TestSqlEntityProcessorDelta.testWithSimpleTransformer <<<
   [junit4]    > Throwable #1: java.lang.RuntimeException: Exception during query
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([2100A32888E1B6E:6D5422D852587763]:0)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:637)
   [junit4]    > 	at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.simpleTransform(AbstractSqlEntityProcessorTestCase.java:116)
   [junit4]    > 	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testWithSimpleTransformer(TestSqlEntityProcessorDelta.java:58)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:738)
   [junit4]    > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='14']
   [junit4]    > 	xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]    > <response>
   [junit4]    > <lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="q">AddAColumn_s:Added</str><str name="start">0</str><str name="qt">standard</str><str name="version">2.2</str><str name="rows">20</str></lst></lst><result name="response" numFound="20" start="0"><doc><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Jacob</str></arr><str name="id">1</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Ethan</str></arr><str name="id">2</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Michael</str></arr><str name="id">3</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NP</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Jayden</str></arr><str name="id">4</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NO</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>William</str></arr><str name="id">5</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Alexander</str></arr><str name="id">6</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Noah</str></arr><str name="id">7</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Daniel</str></arr><str name="id">8</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Aiden</str></arr><str name="id">9</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Anthony</str></arr><str name="id">10</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Emma</str></arr><str name="id">11</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Grace</str></arr><str name="id">12</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Hailey</str></arr><str name="id">13</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Isabella</str></arr><str name="id">14</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Lily</str></arr><str name="id">15</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NC</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Madison</str></arr><str name="id">16</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NA</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Mia</str></arr><str name="id">17</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Natalie</str></arr><str name="id">18</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Olivia</str></arr><str name="id">19</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc><doc><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="AddAColumn_s">Added</str><arr name="NAME_mult_s"><str>Samantha</str></arr><str name="id">20</str><date name="timestamp">2013-11-08T16:03:07.861Z</date></doc></result>
   [junit4]    > </response>
   [junit4]    > 	request was:q=AddAColumn_s:Added&start=0&qt=standard&version=2.2&rows=20
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:630)
   [junit4]    > 	... 42 more
   [junit4]   2> 66017 T199 oas.SolrTestCaseJ4.setUp ###Starting testWithComplexTransformer
   [junit4]   2> 66026 T199 C65 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 66027 T199 C65 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 3
   [junit4]   2> 66034 T199 C65 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 66035 T199 C65 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_5,generation=5}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_6,generation=6}
   [junit4]   2> 66036 T199 C65 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
   [junit4]   2> 66037 T199 C65 oass.SolrIndexSearcher.<init> Opening Searcher@7a907a9 main
   [junit4]   2> 66038 T199 C65 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 66038 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7a907a9 main{StandardDirectoryReader(segments_6:10:nrt)}
   [junit4]   2> 66040 T202 C65 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 66040 T202 C65 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 66041 T202 C65 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 66041 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 66042 T202 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7a907a9 main{StandardDirectoryReader(segments_6:10:nrt)}
   [junit4]   2> 66043 T199 C65 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 10
   [junit4]   2> ASYNC  NEW_CORE C66 name=collection1 org.apache.solr.core.SolrCore@1bf71bf7
   [junit4]   2> 66256 T199 C66 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
   [junit4]   2> 66257 T199 C66 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
   [junit4]   2> 66259 T199 C66 oashd.DataImporter.doFullImport Starting Full Import
   [junit4]   2> 66260 T199 C66 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
   [junit4]   2> 66261 T199 C66 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 66263 T199 C66 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;
   [junit4]   2> 66265 T199 C66 oashd.JdbcDataSource$1.call Time taken for getConnection(): 2
   [junit4]   2> 66293 T199 C66 oashd.DocBuilder.finish Import completed successfully
   [junit4]   2> 66294 T199 C66 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 66302 T199 C66 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_6,generation=6}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@59ba59ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@64126412),segFN=segments_7,generation=7}
   [junit4]   2> 66303 T199 C66 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 7
   [junit4]   2> 66305 T199 C66 oass.SolrIndexSearcher.<init> Opening Searcher@517b517b main
   [junit4]   2> 66306 T199 C66 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 66307 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@517b517b main{StandardDirectoryReader(segments_7:13:nrt _2(4.6):c60)}
   [junit4]   2> 66308 T202 C66 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 66309 T202 C66 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=1 
   [junit4]   2> 66309 T202 C66 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 66310 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 66310 T202 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@517b517b main{StandardDirectoryReader(segments_7:13:nrt _2(4.6):c60)}
   [junit4]   2> 66311 T199 C66 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
   [junit4]   2> 66312 T199 C66 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
   [junit4]   2> 66313 T199 C66 oashd.DocBuilder.execute Time taken = 0:0:0.52
   [junit4]   2> 66314 T199 C66 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={commit=true&synchronous=true&clean=true&command=full-import&indent=true&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"./test3578601346963714124tmp"+filename%3D"the.properties"+/>%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"People.ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"derby"+transformer%3D"TripleThreatTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.People.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a} {deleteByQuery=*:*,add=[1, TripleThreat-1-1, TripleThreat-2-1, 2, TripleThreat-1-2, TripleThreat-2-2, 3, TripleThreat-1-3, TripleThreat-2-3, 4, ... (60 adds)],commit=} 0 60
   [junit4]   2> ASYNC  NEW_CORE C67 name=collection1 org.apache.solr.core.SolrCore@1bf71bf7
   [junit4]   2> 66342 T199 C67 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=*:*

[...truncated too long message...]

e.execute [collection1] webapp=null path=null params={q=solr&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 67661 T202 C75 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&start=0&distrib=false&rows=10&event=newSearcher} hits=0 status=0 QTime=0 
   [junit4]   2> 67662 T202 C75 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=1 
   [junit4]   2> 67663 T202 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 67664 T202 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@34393439 main{StandardDirectoryReader(segments_b:23:nrt _4(4.6):c20/7:delGen=1 _5(4.6):c8)}
   [junit4]   2> 67665 T199 C75 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
   [junit4]   2> 67667 T199 C75 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
   [junit4]   2> 67668 T199 C75 oashd.DocBuilder.execute Time taken = 0:0:0.129
   [junit4]   2> 67669 T199 C75 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={commit=true&synchronous=true&clean=false&command=delta-import&indent=true&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"./test491753836253768952tmp"+filename%3D"the.properties"+/>%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"People.ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"derby"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.People.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a} {delete=[19],add=[10, 1001, 1007, 15, 13, 1, 6, 20],commit=} 0 137
   [junit4]   2> ASYNC  NEW_CORE C76 name=collection1 org.apache.solr.core.SolrCore@1bf71bf7
   [junit4]   2> 67684 T199 C76 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=*:*&start=0&qt=standard&version=2.2&rows=20} hits=21 status=0 QTime=2 
   [junit4]   2> 67689 T199 C76 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
   [junit4]   2> 67690 T199 C76 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
   [junit4]   2> 67691 T199 C76 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:1001&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=0 
   [junit4]   2> 67694 T199 C76 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:1007&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=1 
   [junit4]   2> 67696 T199 C76 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:19&start=0&qt=standard&version=2.2&rows=20} hits=0 status=0 QTime=0 
   [junit4]   2> ASYNC  NEW_CORE C77 name=collection1 org.apache.solr.core.SolrCore@1bf71bf7
   [junit4]   2> 67706 T199 C77 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:1&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=0 
   [junit4]   2> 67710 T199 C77 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:20&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=1 
   [junit4]   2> 67713 T199 C77 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:6&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=0 
   [junit4]   2> 67717 T199 C77 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:10&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=1 
   [junit4]   2> ASYNC  NEW_CORE C78 name=collection1 org.apache.solr.core.SolrCore@1bf71bf7
   [junit4]   2> 67729 T199 C78 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:13&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=0 
   [junit4]   2> 67733 T199 C78 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:15&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=1 
   [junit4]   2> 68242 T199 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/solr/collection1/conf/dataimport.properties
   [junit4]   2> 68243 T199 oas.SolrTestCaseJ4.tearDown ###Ending testSingleEntity
   [junit4]   2> 68259 T199 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 68259 T199 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=299045331
   [junit4]   2> 68260 T199 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1bf71bf7
   [junit4]   2> 68260 T199 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=10,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=140,cumulative_deletesById=2,cumulative_deletesByQuery=8,cumulative_errors=0}
   [junit4]   2> 68261 T199 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 68261 T199 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 68262 T199 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 68263 T199 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 68264 T199 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 68265 T199 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146/index;done=false>>]
   [junit4]   2> 68265 T199 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146/index
   [junit4]   2> 68266 T199 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146;done=false>>]
   [junit4]   2> 68266 T199 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J0/./solrtest-TestSqlEntityProcessorDelta-1383926587146
   [junit4]   2> NOTE: test params are: codec=Lucene45, sim=DefaultSimilarity, locale=ja_JP_JP, timezone=Asia/Ashgabat
   [junit4]   2> NOTE: Linux 3.8.0-32-generic amd64/IBM Corporation 1.6.0 (64-bit)/cpus=8,threads=1,free=21722328,total=42650624
   [junit4]   2> NOTE: All tests run in this JVM: [TestSolrEntityProcessorUnit, TestDocBuilder, TestNumberFormatTransformer, TestSimplePropertiesWriter, TestSqlEntityProcessor, TestScriptTransformer, TestFieldReader, TestEphemeralCache, TestVariableResolver, TestPlainTextEntityProcessor, TestNonWritablePersistFile, TestClobTransformer, TestDateFormatTransformer, TestDocBuilder2, TestDataConfig, TestVariableResolverEndToEnd, TestTemplateTransformer, TestZKPropertiesWriter, TestSolrEntityProcessorEndToEnd, TestSqlEntityProcessorDelta]
   [junit4] Completed in 3.15s, 4 tests, 2 errors <<< FAILURES!

[...truncated 52 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:428: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:421: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:209: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:451: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:483: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1275: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:911: There were test failures: 35 suites, 143 tests, 2 errors, 3 ignored

Total time: 47 minutes 56 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/ibm-j9-jdk6 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure