lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@sd-datasolutions.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.7.0_09) - Build # 2986 - Still Failing!
Date Fri, 30 Nov 2012 22:16:01 GMT
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-trunk-Linux/2986/
Java: 64bit/jdk1.7.0_09 -XX:+UseSerialGC

1 tests failed.
FAILED:  org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testChildEntities

Error Message:
Exception during query

Stack Trace:
java.lang.RuntimeException: Exception during query
	at __randomizedtesting.SeedInfo.seed([848285587C7790C5:BE16ABC47FE8D46]:0)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:515)
	at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.withChildEntities(AbstractSqlEntityProcessorTestCase.java:165)
	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testChildEntities(TestSqlEntityProcessorDelta.java:66)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	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:45)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	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:45)
	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:722)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='19']
	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="start">0</str><str name="q">*:*</str><str name="qt">standard</str><str name="rows">20</str><str name="version">2.2</str></lst></lst><result name="response" numFound="20" start="0"><doc><arr name="NAME_mult_s"><str>Jacob</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="id">1</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Swimming</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Ethan</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="id">2</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Triathlon</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Michael</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="id">3</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Water polo</str><str>Underwater rugby</str><str>Kayaking</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Jayden</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NP</str></arr><str name="id">4</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Snorkeling</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>William</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NO</str></arr><str name="id">5</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Synchronized diving</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Alexander</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="id">6</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Underwater rugby</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Noah</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="id">7</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Boating</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Daniel</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="id">8</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Bodyboarding</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Aiden</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="id">9</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Canoeing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Anthony</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="id">10</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Fishing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Emma</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="id">11</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Jet Ski</str><str>Rowing</str><str>Sailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Grace</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="id">12</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Kayaking</str><str>Canoeing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Hailey</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="id">13</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Kite surfing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Isabella</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="id">14</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Parasailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Lily</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="id">15</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Rafting</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Madison</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NC</str></arr><str name="id">16</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Rowing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Mia</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NA</str></arr><str name="id">17</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Sailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Natalie</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="id">18</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>White Water Rafting</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Olivia</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="id">19</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Water skiing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Samantha</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="id">20</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Windsurfing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc></result>
</response>

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




Build Log:
[...truncated 11879 lines...]
[junit4:junit4] Suite: org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
[junit4:junit4]   2> Fri Nov 30 17:15:47 EST 2012 Thread[SUITE-TestSqlEntityProcessorDelta-seed#[848285587C7790C5]-worker,5,TGRP-TestSqlEntityProcessorDelta] java.lang.ClassNotFoundException: DerbyUtil
[junit4:junit4]   2> 576 T43 oas.SolrTestCaseJ4.initCore ####initCore
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 578 T43 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/collection1/'
[junit4:junit4]   2> 623 T43 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 698 T43 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4:junit4]   2> 699 T43 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 714 T43 oass.IndexSchema.readSchema Schema name=dih_test
[junit4:junit4]   2> 796 T43 oass.IndexSchema.readSchema default search field in schema is desc
[junit4:junit4]   2> 797 T43 oass.IndexSchema.readSchema query parser default operator is OR
[junit4:junit4]   2> 798 T43 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 800 T43 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 801 T43 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr
[junit4:junit4]   2> 801 T43 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/'
[junit4:junit4]   2> 808 T43 oasc.CoreContainer.<init> New CoreContainer 1589242951
[junit4:junit4]   2> 809 T43 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/
[junit4:junit4]   2> 810 T43 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 810 T43 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:junit4]   2> 810 T43 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4:junit4]   2> 811 T43 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 811 T43 oasc.CachingDirectoryFactory.injectLockFactory WARNING No lockType configured for MockDirWrapper(org.apache.lucene.store.RAMDirectory@4759e7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4c5f4cd5) assuming 'simple'
[junit4:junit4]   2> 812 T43 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861 forceNew:false
[junit4:junit4]   2> 812 T43 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 813 T43 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index/
[junit4:junit4]   2> 813 T43 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 814 T43 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index forceNew:false
[junit4:junit4]   2> 815 T43 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 816 T43 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 816 T43 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 818 T43 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "" (default)
[junit4:junit4]   2> 819 T43 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 820 T43 oasc.RequestHandlers.initHandlersFromConfig created /dataimport: org.apache.solr.handler.dataimport.DataImportHandler
[junit4:junit4]   2> 821 T43 oasc.RequestHandlers.initHandlersFromConfig created /search: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 823 T43 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 825 T43 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 828 T43 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 829 T43 oass.SolrIndexSearcher.<init> Opening Searcher@21f52bf4 main
[junit4:junit4]   2> 829 T43 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 830 T43 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 830 T43 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 831 T43 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 831 T43 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 831 T43 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 832 T43 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 832 T43 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 832 T43 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 833 T43 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 833 T43 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 834 T43 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 838 T43 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 838 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@21f52bf4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 839 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 840 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@21f52bf4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 841 T43 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4:junit4]   2> 848 T43 oas.SolrTestCaseJ4.setUp ###Starting testWithComplexTransformer
[junit4:junit4]   2> ASYNC  NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@5b1aaec3
[junit4:junit4]   2> 861 T43 C2 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 861 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 863 T43 C2 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 863 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 864 T43 C2 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 11
[junit4:junit4]   2> 876 T43 C2 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 877 T43 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 877 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 878 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 878 T43 C2 oass.SolrIndexSearcher.<init> Opening Searcher@6c5bb8f7 main
[junit4:junit4]   2> 879 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@6c5bb8f7 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 879 T43 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 880 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 881 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 881 T45 C2 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 882 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 882 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6c5bb8f7 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 883 T45 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 883 T43 C2 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 8
[junit4:junit4]   2> 1109 T43 C2 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1109 T43 C2 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1110 T43 C2 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 1110 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1123 T43 C2 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1127 T43 C2 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1128 T43 C2 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1220 T43 C2 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1221 T43 C2 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1310 T43 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_3,generation=3,filenames=[_0_Asserting_0.tim, _0.fnm, _0_Asserting_0.tip, _0_MockSep_0.tib, _0_Lucene41_0.doc, _0_MockSep_0.skp, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.doc, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Asserting_0.doc, _0_Lucene41_0.tip, segments_3]
[junit4:junit4]   2> 1311 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0_Asserting_0.tim, _0.fnm, _0_Asserting_0.tip, _0_MockSep_0.tib, _0_Lucene41_0.doc, _0_MockSep_0.skp, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.doc, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Asserting_0.doc, _0_Lucene41_0.tip, segments_3]
[junit4:junit4]   2> 1312 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 1335 T43 C2 oass.SolrIndexSearcher.<init> Opening Searcher@69a93a44 main
[junit4:junit4]   2> 1336 T43 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1337 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@69a93a44 main{StandardDirectoryReader(segments_3:5 _0(5.0):C60)}
[junit4:junit4]   2> 1338 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1338 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1339 T45 C2 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1339 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1340 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@69a93a44 main{StandardDirectoryReader(segments_3:5 _0(5.0):C60)}
[junit4:junit4]   2> 1340 T45 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 1341 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1342 T43 C2 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1342 T43 C2 oashd.DocBuilder.execute Time taken = 0:0:0.231
[junit4:junit4]   2> 1343 T43 C2 UPDATE [collection1] webapp=null path=null params={indent=true&clean=true&commit=true&dataConfig=<dataConfig>+%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"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.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.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.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&command=full-import&synchronous=true} {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 239
[junit4:junit4]   2> 1393 T43 C2 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=60} hits=60 status=0 QTime=46 
[junit4:junit4]   2> 1436 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:TripleThreat-1-*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=6 
[junit4:junit4]   2> 1450 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:TripleThreat-2-*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=1 
[junit4:junit4]   2> 1482 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=%2Bid:TripleThreat-1-3+%2BNAME_mult_s:Michael+%2BNAME_mult_s:leahciM++%2BCOUNTRY_CODES_mult_s:NR+%2BCOUNTRY_CODES_mult_s:RN&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=17 
[junit4:junit4]   2> 1488 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=1 
[junit4:junit4]   2> 1500 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1501 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1514 T43 C2 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1514 T43 C2 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1515 T43 C2 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 1516 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1518 T43 C2 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 1519 T43 C2 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 1520 T43 C2 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1521 T43 C2 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1531 T43 C2 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 4
[junit4:junit4]   2> 1531 T43 C2 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 7
[junit4:junit4]   2> 1532 T43 C2 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 1533 T43 C2 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 1534 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 10
[junit4:junit4]   2> 1535 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 12
[junit4:junit4]   2> 1536 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 15
[junit4:junit4]   2> 1536 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 2
[junit4:junit4]   2> 1537 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 3
[junit4:junit4]   2> 1538 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 20
[junit4:junit4]   2> 1538 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 7
[junit4:junit4]   2> 1554 T43 C2 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 1555 T43 C2 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1556 T43 C2 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1582 T43 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_3,generation=3,filenames=[_0_Asserting_0.tim, _0.fnm, _0_Asserting_0.tip, _0_MockSep_0.tib, _0_Lucene41_0.doc, _0_MockSep_0.skp, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.doc, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Asserting_0.doc, _0_Lucene41_0.tip, segments_3]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_4,generation=4,filenames=[_0_Asserting_0.tim, _1_Lucene41_0.doc, _0_Asserting_0.tip, _1_Asserting_0.doc, _1.fnm, _1_Asserting_0.tim, _0_MockSep_0.skp, _1_Asserting_0.tip, _0.si, _0_MockSep_0.doc, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_Asserting_0.doc, _1_MockSep_0.doc, _1_MockSep_0.skp, _0.fnm, _1_MockSep_0.tib, _1_Lucene41_0.tim, _0_1.del, _1_Lucene41_0.tip, _1_MockSep_0.tii, _0_MockSep_0.tib, _1.fdx, _1.fdt, _0_Lucene41_0.doc, _1.si, _0.fdx, _0_MockSep_0.tii, _0.fdt, segments_4]
[junit4:junit4]   2> 1583 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_0_Asserting_0.tim, _1_Lucene41_0.doc, _0_Asserting_0.tip, _1_Asserting_0.doc, _1.fnm, _1_Asserting_0.tim, _0_MockSep_0.skp, _1_Asserting_0.tip, _0.si, _0_MockSep_0.doc, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_Asserting_0.doc, _1_MockSep_0.doc, _1_MockSep_0.skp, _0.fnm, _1_MockSep_0.tib, _1_Lucene41_0.tim, _0_1.del, _1_Lucene41_0.tip, _1_MockSep_0.tii, _0_MockSep_0.tib, _1.fdx, _1.fdt, _0_Lucene41_0.doc, _1.si, _0.fdx, _0_MockSep_0.tii, _0.fdt, segments_4]
[junit4:junit4]   2> 1584 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 1592 T43 C2 oass.SolrIndexSearcher.<init> Opening Searcher@6ea54ad6 main
[junit4:junit4]   2> 1593 T43 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1601 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@6ea54ad6 main{StandardDirectoryReader(segments_4:8 _0(5.0):C60/13 _1(5.0):C12)}
[junit4:junit4]   2> 1602 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1603 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1604 T45 C2 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1604 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1605 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6ea54ad6 main{StandardDirectoryReader(segments_4:8 _0(5.0):C60/13 _1(5.0):C12)}
[junit4:junit4]   2> 1605 T45 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 1606 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1607 T43 C2 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1608 T43 C2 oashd.DocBuilder.execute Time taken = 0:0:0.91
[junit4:junit4]   2> 1609 T43 C2 UPDATE [collection1] webapp=null path=null params={indent=true&clean=false&commit=true&dataConfig=<dataConfig>+%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"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.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.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.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&command=delta-import&synchronous=true} {delete=[10, 12, 15, 2, 3, 20, 7],add=[1, TripleThreat-1-1, TripleThreat-2-1, 19, TripleThreat-1-19, TripleThreat-2-19, 1003, TripleThreat-1-1003, TripleThreat-2-1003, 1019, ... (12 adds)],commit=} 0 102
[junit4:junit4]   2> 1612 T43 C2 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=45} hits=59 status=0 QTime=0 
[junit4:junit4]   2> 1643 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:TripleThreat-1-*&qt=standard&rows=20&version=2.2} hits=22 status=0 QTime=1 
[junit4:junit4]   2> 1653 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:TripleThreat-2-*&qt=standard&rows=20&version=2.2} hits=22 status=0 QTime=0 
[junit4:junit4]   2> 1668 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=22 status=0 QTime=1 
[junit4:junit4]   2> 1675 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1676 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1677 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:1003&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1681 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:1019&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 1684 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:2&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1687 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:3&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1690 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:20&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1692 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:7&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1695 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:10&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1698 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:12&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1701 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:15&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1704 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:1&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 1708 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:19&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1714 T43 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 1715 T43 oas.SolrTestCaseJ4.tearDown ###Ending testWithComplexTransformer
[junit4:junit4]   2> 1729 T43 oas.SolrTestCaseJ4.setUp ###Starting testSingleEntity
[junit4:junit4]   2> 1732 T43 C2 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1733 T43 C2 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 1748 T43 C2 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1749 T43 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_4,generation=4,filenames=[_0_Asserting_0.tim, _1_Lucene41_0.doc, _0_Asserting_0.tip, _1_Asserting_0.doc, _1.fnm, _1_Asserting_0.tim, _0_MockSep_0.skp, _1_Asserting_0.tip, _0.si, _0_MockSep_0.doc, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_Asserting_0.doc, _1_MockSep_0.doc, _1_MockSep_0.skp, _0.fnm, _1_MockSep_0.tib, _1_Lucene41_0.tim, _0_1.del, _1_Lucene41_0.tip, _1_MockSep_0.tii, _0_MockSep_0.tib, _1.fdx, _1.fdt, _0_Lucene41_0.doc, _1.si, _0.fdx, _0_MockSep_0.tii, _0.fdt, segments_4]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 1750 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 5[segments_5]
[junit4:junit4]   2> 1751 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 1752 T43 C2 oass.SolrIndexSearcher.<init> Opening Searcher@51f096bc main
[junit4:junit4]   2> 1752 T43 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1754 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@51f096bc main{StandardDirectoryReader(segments_5:9)}
[junit4:junit4]   2> 1754 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1755 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1755 T45 C2 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1756 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1756 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@51f096bc main{StandardDirectoryReader(segments_5:9)}
[junit4:junit4]   2> 1757 T45 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 1758 T43 C2 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 11
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> Fri Nov 30 17:15:49 EST 2012:
[junit4:junit4]   2> Booting Derby version The Apache Software Foundation - Apache Derby - 10.9.1.0 - (1344872): instance a816c00e-013b-5363-cd74-000005fcfc38 
[junit4:junit4]   2> on database directory memory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/derbyDB  with class loader sun.misc.Launcher$AppClassLoader@663c0737 
[junit4:junit4]   2> Loaded from file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar
[junit4:junit4]   2> java.vendor=Oracle Corporation
[junit4:junit4]   2> java.runtime.version=1.7.0_09-b05
[junit4:junit4]   2> user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1
[junit4:junit4]   2> derby.system.home=null
[junit4:junit4]   2> derby.stream.error.field=DerbyUtil.DEV_NULL
[junit4:junit4]   2> Database Class Loader started - derby.database.classpath=''
[junit4:junit4]   2> 3310 T43 C2 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 3311 T43 C2 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 3311 T43 C2 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 3312 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3313 T43 C2 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 3314 T43 C2 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;
[junit4:junit4]   2> 3316 T43 C2 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 3404 T43 C2 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 3404 T43 C2 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 3409 T43 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_6,generation=6,filenames=[_2.si, _2_Asserting_0.tim, _2_Lucene41_0.tim, _2_Asserting_0.tip, _2_Asserting_0.doc, _2_MockSep_0.skp, _2.fdt, _2_MockSep_0.tii, _2_Lucene41_0.doc, _2_MockSep_0.tib, _2_Lucene41_0.tip, _2.fdx, _2_MockSep_0.doc, segments_6, _2.fnm]
[junit4:junit4]   2> 3410 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 6[_2.si, _2_Asserting_0.tim, _2_Lucene41_0.tim, _2_Asserting_0.tip, _2_Asserting_0.doc, _2_MockSep_0.skp, _2.fdt, _2_MockSep_0.tii, _2_Lucene41_0.doc, _2_MockSep_0.tib, _2_Lucene41_0.tip, _2.fdx, _2_MockSep_0.doc, segments_6, _2.fnm]
[junit4:junit4]   2> 3410 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 3412 T43 C2 oass.SolrIndexSearcher.<init> Opening Searcher@2f028d54 main
[junit4:junit4]   2> 3413 T43 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 3418 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2f028d54 main{StandardDirectoryReader(segments_6:12 _2(5.0):C20)}
[junit4:junit4]   2> 3419 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 3420 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 3420 T45 C2 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 3421 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 3421 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2f028d54 main{StandardDirectoryReader(segments_6:12 _2(5.0):C20)}
[junit4:junit4]   2> 3421 T45 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 3422 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3423 T43 C2 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 3423 T43 C2 oashd.DocBuilder.execute Time taken = 0:0:0.110
[junit4:junit4]   2> 3424 T43 C2 UPDATE [collection1] webapp=null path=null params={indent=true&clean=true&commit=true&dataConfig=<dataConfig>+%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.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.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.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&command=full-import&synchronous=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 117
[junit4:junit4]   2> 3462 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=3 
[junit4:junit4]   2> 3475 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 3476 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 3521 T43 C2 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 3521 T43 C2 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 3522 T43 C2 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 3522 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3524 T43 C2 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 3525 T43 C2 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 3526 T43 C2 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;
[junit4:junit4]   2> 3528 T43 C2 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 3600 T43 C2 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 1
[junit4:junit4]   2> 3601 T43 C2 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
[junit4:junit4]   2> 3601 T43 C2 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 3614 T43 C2 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 3615 T43 C2 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 3615 T43 C2 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 3619 T43 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_6,generation=6,filenames=[_2.si, _2_Asserting_0.tim, _2_Lucene41_0.tim, _2_Asserting_0.tip, _2_Asserting_0.doc, _2_MockSep_0.skp, _2.fdt, _2_MockSep_0.tii, _2_Lucene41_0.doc, _2_MockSep_0.tib, _2_Lucene41_0.tip, _2.fdx, _2_MockSep_0.doc, segments_6, _2.fnm]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_7,generation=7,filenames=[_2.si, _3_MockSep_0.doc, _2_Lucene41_0.tim, _2_MockSep_0.skp, _3.fnm, _3.fdt, _2_Lucene41_0.tip, _2_MockSep_0.doc, _3_Lucene41_0.tip, _2_Asserting_0.doc, _3_MockSep_0.tib, _3_Lucene41_0.tim, _2.fdt, _2_MockSep_0.tii, _2_Lucene41_0.doc, _2_MockSep_0.tib, _3_MockSep_0.tii, _2.fdx, _2.fnm, _3.fdx, _2_Asserting_0.tim, segments_7, _2_Asserting_0.tip, _3_Lucene41_0.doc, _3_Asserting_0.tim, _3_Asserting_0.tip, _3_Asserting_0.doc, _3.si, _3_MockSep_0.skp]
[junit4:junit4]   2> 3620 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 7[_2.si, _3_MockSep_0.doc, _2_Lucene41_0.tim, _2_MockSep_0.skp, _3.fnm, _3.fdt, _2_Lucene41_0.tip, _2_MockSep_0.doc, _3_Lucene41_0.tip, _2_Asserting_0.doc, _3_MockSep_0.tib, _3_Lucene41_0.tim, _2.fdt, _2_MockSep_0.tii, _2_Lucene41_0.doc, _2_MockSep_0.tib, _3_MockSep_0.tii, _2.fdx, _2.fnm, _3.fdx, _2_Asserting_0.tim, segments_7, _2_Asserting_0.tip, _3_Lucene41_0.doc, _3_Asserting_0.tim, _3_Asserting_0.tip, _3_Asserting_0.doc, _3.si, _3_MockSep_0.skp]
[junit4:junit4]   2> 3621 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 3623 T43 C2 oass.SolrIndexSearcher.<init> Opening Searcher@412be22b main
[junit4:junit4]   2> 3624 T43 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 3630 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@412be22b main{StandardDirectoryReader(segments_7:14 _2(5.0):C20 _3(5.0):C1)}
[junit4:junit4]   2> 3631 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 3631 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 3632 T45 C2 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 3632 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 3633 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@412be22b main{StandardDirectoryReader(segments_7:14 _2(5.0):C20 _3(5.0):C1)}
[junit4:junit4]   2> 3633 T45 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 3634 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3635 T43 C2 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 3635 T43 C2 oashd.DocBuilder.execute Time taken = 0:0:0.112
[junit4:junit4]   2> 3635 T43 C2 UPDATE [collection1] webapp=null path=null params={indent=true&clean=false&commit=true&dataConfig=<dataConfig>+%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"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.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.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.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&command=delta-import&synchronous=true} {add=[1010],commit=} 0 118
[junit4:junit4]   2> 3641 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=21 status=0 QTime=2 
[junit4:junit4]   2> 3649 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 3650 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 3651 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:1010&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> Fri Nov 30 17:15:50 EST 2012:
[junit4:junit4]   2> Shutting down instance a816c00e-013b-5363-cd74-000005fcfc38 on database directory memory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/derbyDB with class loader sun.misc.Launcher$AppClassLoader@663c0737 
[junit4:junit4]   2> 4182 T43 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 4183 T43 oas.SolrTestCaseJ4.tearDown ###Ending testSingleEntity
[junit4:junit4]   2> 4193 T43 oas.SolrTestCaseJ4.setUp ###Starting testChildEntities
[junit4:junit4]   2> 4198 T43 C2 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 4199 T43 C2 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4:junit4]   2> 4206 T43 C2 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 4207 T43 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_7,generation=7,filenames=[_2.si, _3_MockSep_0.doc, _2_Lucene41_0.tim, _2_MockSep_0.skp, _3.fnm, _3.fdt, _2_Lucene41_0.tip, _2_MockSep_0.doc, _3_Lucene41_0.tip, _2_Asserting_0.doc, _3_MockSep_0.tib, _3_Lucene41_0.tim, _2.fdt, _2_MockSep_0.tii, _2_Lucene41_0.doc, _2_MockSep_0.tib, _3_MockSep_0.tii, _2.fdx, _2.fnm, _3.fdx, _2_Asserting_0.tim, segments_7, _2_Asserting_0.tip, _3_Lucene41_0.doc, _3_Asserting_0.tim, _3_Asserting_0.tip, _3_Asserting_0.doc, _3.si, _3_MockSep_0.skp]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 4208 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 8[segments_8]
[junit4:junit4]   2> 4209 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 4210 T43 C2 oass.SolrIndexSearcher.<init> Opening Searcher@36438af4 main
[junit4:junit4]   2> 4211 T43 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 4212 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@36438af4 main{StandardDirectoryReader(segments_8:15)}
[junit4:junit4]   2> 4213 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 4213 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4214 T45 C2 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4215 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 4215 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36438af4 main{StandardDirectoryReader(segments_8:15)}
[junit4:junit4]   2> 4216 T45 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 4217 T43 C2 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 11
[junit4:junit4]   2> 4257 T43 C2 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 4258 T43 C2 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 4258 T43 C2 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 4259 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 4260 T43 C2 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 4261 T43 C2 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 4262 T43 C2 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 4274 T43 C2 oashd.JdbcDataSource$1.call Creating a connection for entity Sports with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 4275 T43 C2 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 4301 T43 C2 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 4301 T43 C2 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 4311 T43 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_9,generation=9,filenames=[_4_NestedPulsing_0.doc, _4_Lucene41_0.doc, _4_MockSep_0.tib, _4_MockSep_0.skp, _4.fnm, _4_Asserting_0.tip, _4.fdt, _4.si, _4_Lucene41_0.tip, _4_Lucene41_0.tim, segments_9, _4.fdx, _4_Asserting_0.tim, _4_NestedPulsing_0.tip, _4_MockSep_0.doc, _4_NestedPulsing_0.tim, _4_Asserting_0.doc, _4_MockSep_0.tii]
[junit4:junit4]   2> 4312 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 9[_4_NestedPulsing_0.doc, _4_Lucene41_0.doc, _4_MockSep_0.tib, _4_MockSep_0.skp, _4.fnm, _4_Asserting_0.tip, _4.fdt, _4.si, _4_Lucene41_0.tip, _4_Lucene41_0.tim, segments_9, _4.fdx, _4_Asserting_0.tim, _4_NestedPulsing_0.tip, _4_MockSep_0.doc, _4_NestedPulsing_0.tim, _4_Asserting_0.doc, _4_MockSep_0.tii]
[junit4:junit4]   2> 4312 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 4317 T43 C2 oass.SolrIndexSearcher.<init> Opening Searcher@17f1bc1a main
[junit4:junit4]   2> 4318 T43 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 4324 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@17f1bc1a main{StandardDirectoryReader(segments_9:18 _4(5.0):C20)}
[junit4:junit4]   2> 4325 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 4325 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4326 T45 C2 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4327 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 4327 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17f1bc1a main{StandardDirectoryReader(segments_9:18 _4(5.0):C20)}
[junit4:junit4]   2> 4328 T45 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 4329 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 4329 T43 C2 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 4330 T43 C2 oashd.DocBuilder.execute Time taken = 0:0:0.71
[junit4:junit4]   2> 4330 T43 C2 UPDATE [collection1] webapp=null path=null params={indent=true&clean=true&commit=true&dataConfig=<dataConfig>+%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.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.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.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"Sports"+dataSource%3D"hsqldb"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+ID,+SPORT_NAME+FROM+PEOPLE_SPORTS+WHERE+DELETED+!%3D+'Y'+AND+PERSON_ID%3D${People.ID}+ORDER+BY+ID"+>+%0a<field+column%3D"SPORT_NAME"+name%3D"SPORT_NAME_mult_s"+/>+%0a<field+column%3D"id"+name%3D"SPORT_ID_mult_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=full-import&synchronous=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 78
[junit4:junit4]   2> 4332 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=1 
[junit4:junit4]   2> 4347 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=1 
[junit4:junit4]   2> 4360 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=SPORT_NAME_mult_s:Sailing&qt=standard&rows=20&version=2.2} hits=2 status=0 QTime=4 
[junit4:junit4]   2> 4365 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=NAME_mult_s:Michael&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 4371 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 4372 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 4379 T43 C2 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 4380 T43 C2 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 4380 T43 C2 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 4381 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 4382 T43 C2 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 4383 T43 C2 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: Sports
[junit4:junit4]   2> 4383 T43 C2 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: Sports rows obtained : 0
[junit4:junit4]   2> 4384 T43 C2 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: Sports rows obtained : 0
[junit4:junit4]   2> 4384 T43 C2 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: Sports
[junit4:junit4]   2> 4384 T43 C2 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 4385 T43 C2 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 4385 T43 C2 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 4389 T43 C2 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 0
[junit4:junit4]   2> 4389 T43 C2 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
[junit4:junit4]   2> 4390 T43 C2 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 4391 T43 C2 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 4391 T43 C2 oashd.DocBuilder.execute Time taken = 0:0:0.9
[junit4:junit4]   2> 4392 T43 C2 UPDATE [collection1] webapp=null path=null params={indent=true&clean=false&commit=true&dataConfig=<dataConfig>+%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.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.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.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"Sports"+dataSource%3D"hsqldb"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+ID,+SPORT_NAME+FROM+PEOPLE_SPORTS+WHERE+DELETED+!%3D+'Y'+AND+PERSON_ID%3D${People.ID}+ORDER+BY+ID"+>+%0a<field+column%3D"SPORT_NAME"+name%3D"SPORT_NAME_mult_s"+/>+%0a<field+column%3D"id"+name%3D"SPORT_ID_mult_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=delta-import&synchronous=true} {} 0 16
[junit4:junit4]   2> 4394 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=1 
[junit4:junit4]   2> 4416 T43 oas.SolrTestCaseJ4.assertQ SEVERE REQUEST FAILED: xpath=//*[@numFound='19']
[junit4:junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4:junit4]   2> 	<response>
[junit4:junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="start">0</str><str name="q">*:*</str><str name="qt">standard</str><str name="rows">20</str><str name="version">2.2</str></lst></lst><result name="response" numFound="20" start="0"><doc><arr name="NAME_mult_s"><str>Jacob</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="id">1</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Swimming</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Ethan</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="id">2</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Triathlon</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Michael</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="id">3</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Water polo</str><str>Underwater rugby</str><str>Kayaking</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Jayden</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NP</str></arr><str name="id">4</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Snorkeling</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>William</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NO</str></arr><str name="id">5</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Synchronized diving</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Alexander</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="id">6</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Underwater rugby</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Noah</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="id">7</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Boating</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Daniel</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="id">8</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Bodyboarding</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Aiden</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="id">9</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Canoeing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Anthony</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="id">10</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Fishing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Emma</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="id">11</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Jet Ski</str><str>Rowing</str><str>Sailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Grace</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="id">12</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Kayaking</str><str>Canoeing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Hailey</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="id">13</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Kite surfing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Isabella</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="id">14</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Parasailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Lily</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="id">15</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Rafting</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Madison</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NC</str></arr><str name="id">16</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Rowing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Mia</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NA</str></arr><str name="id">17</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Sailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Natalie</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="id">18</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>White Water Rafting</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Olivia</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="id">19</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Water skiing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Samantha</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="id">20</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Windsurfing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc></result>
[junit4:junit4]   2> 	</response>
[junit4:junit4]   2> 	
[junit4:junit4]   2> 		request was:start=0&q=*:*&qt=standard&rows=20&version=2.2
[junit4:junit4]   2> 4419 T43 oasc.SolrException.log SEVERE REQUEST FAILED: start=0&q=*:*&qt=standard&rows=20&version=2.2:java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='19']
[junit4:junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4:junit4]   2> 	<response>
[junit4:junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="start">0</str><str name="q">*:*</str><str name="qt">standard</str><str name="rows">20</str><str name="version">2.2</str></lst></lst><result name="response" numFound="20" start="0"><doc><arr name="NAME_mult_s"><str>Jacob</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="id">1</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Swimming</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Ethan</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="id">2</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Triathlon</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Michael</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="id">3</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Water polo</str><str>Underwater rugby</str><str>Kayaking</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Jayden</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NP</str></arr><str name="id">4</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Snorkeling</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>William</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NO</str></arr><str name="id">5</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Synchronized diving</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Alexander</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="id">6</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Underwater rugby</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Noah</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="id">7</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Boating</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Daniel</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="id">8</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Bodyboarding</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Aiden</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="id">9</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Canoeing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Anthony</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="id">10</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Fishing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Emma</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="id">11</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Jet Ski</str><str>Rowing</str><str>Sailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Grace</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="id">12</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Kayaking</str><str>Canoeing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Hailey</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="id">13</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Kite surfing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Isabella</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="id">14</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Parasailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Lily</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="id">15</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Rafting</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Madison</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NC</str></arr><str name="id">16</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Rowing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Mia</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NA</str></arr><str name="id">17</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Sailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Natalie</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="id">18</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>White Water Rafting</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Olivia</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="id">19</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Water skiing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Samantha</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="id">20</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Windsurfing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc></result>
[junit4:junit4]   2> 	</response>
[junit4:junit4]   2> 	
[junit4:junit4]   2> 		request was:start=0&q=*:*&qt=standard&rows=20&version=2.2
[junit4:junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:508)
[junit4:junit4]   2> 		at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.withChildEntities(AbstractSqlEntityProcessorTestCase.java:165)
[junit4:junit4]   2> 		at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testChildEntities(TestSqlEntityProcessorDelta.java:66)
[junit4:junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4]   2> 		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]   2> 		at java.lang.reflect.Method.invoke(Method.java:601)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]   2> 		at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 	
[junit4:junit4]   2> 4422 T43 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 4423 T43 oas.SolrTestCaseJ4.tearDown ###Ending testChildEntities
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSqlEntityProcessorDelta -Dtests.method=testChildEntities -Dtests.seed=848285587C7790C5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fr -Dtests.timezone=America/Cayman -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR   0.30s J1 | TestSqlEntityProcessorDelta.testChildEntities <<<
[junit4:junit4]    > Throwable #1: java.lang.RuntimeException: Exception during query
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([848285587C7790C5:BE16ABC47FE8D46]:0)
[junit4:junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:515)
[junit4:junit4]    > 	at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.withChildEntities(AbstractSqlEntityProcessorTestCase.java:165)
[junit4:junit4]    > 	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testChildEntities(TestSqlEntityProcessorDelta.java:66)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:601)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]    > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='19']
[junit4:junit4]    > 	xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4:junit4]    > <response>
[junit4:junit4]    > <lst name="responseHeader"><int name="status">0</int><int name="QTime">1</int><lst name="params"><str name="start">0</str><str name="q">*:*</str><str name="qt">standard</str><str name="rows">20</str><str name="version">2.2</str></lst></lst><result name="response" numFound="20" start="0"><doc><arr name="NAME_mult_s"><str>Jacob</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="id">1</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Swimming</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Ethan</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="id">2</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Triathlon</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Michael</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="id">3</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Water polo</str><str>Underwater rugby</str><str>Kayaking</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Jayden</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NP</str></arr><str name="id">4</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Snorkeling</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>William</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NO</str></arr><str name="id">5</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Synchronized diving</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Alexander</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="id">6</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Underwater rugby</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Noah</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="id">7</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Boating</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Daniel</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="id">8</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Bodyboarding</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Aiden</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="id">9</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Canoeing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Anthony</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="id">10</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Fishing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Emma</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NL</str></arr><str name="id">11</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Jet Ski</str><str>Rowing</str><str>Sailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Grace</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NI</str></arr><str name="id">12</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Kayaking</str><str>Canoeing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Hailey</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NG</str></arr><str name="id">13</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Kite surfing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Isabella</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NF</str></arr><str name="id">14</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Parasailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Lily</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NE</str></arr><str name="id">15</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Rafting</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Madison</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NC</str></arr><str name="id">16</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Rowing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Mia</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NA</str></arr><str name="id">17</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Sailing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Natalie</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NZ</str></arr><str name="id">18</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>White Water Rafting</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Olivia</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NU</str></arr><str name="id">19</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Water skiing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc><doc><arr name="NAME_mult_s"><str>Samantha</str></arr><arr name="COUNTRY_CODES_mult_s"><str>NR</str></arr><str name="id">20</str><str name="AddAColumn_s">Added</str><arr name="SPORT_NAME_mult_s"><str>Windsurfing</str></arr><date name="timestamp">2012-11-30T22:15:51.536Z</date></doc></result>
[junit4:junit4]    > </response>
[junit4:junit4]    > 
[junit4:junit4]    > 	request was:start=0&q=*:*&qt=standard&rows=20&version=2.2
[junit4:junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:508)
[junit4:junit4]    > 	... 42 more
[junit4:junit4]   2> 4501 T43 oas.SolrTestCaseJ4.setUp ###Starting testWithSimpleTransformer
[junit4:junit4]   2> 4509 T43 C2 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 4511 T43 C2 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4:junit4]   2> 4517 T43 C2 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 4519 T43 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_9,generation=9,filenames=[_4_NestedPulsing_0.doc, _4_Lucene41_0.doc, _4_MockSep_0.tib, _4_MockSep_0.skp, _4.fnm, _4_Asserting_0.tip, _4.fdt, _4.si, _4_Lucene41_0.tip, _4_Lucene41_0.tim, segments_9, _4.fdx, _4_Asserting_0.tim, _4_NestedPulsing_0.tip, _4_MockSep_0.doc, _4_NestedPulsing_0.tim, _4_Asserting_0.doc, _4_MockSep_0.tii]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_a,generation=10,filenames=[segments_a]
[junit4:junit4]   2> 4520 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 10[segments_a]
[junit4:junit4]   2> 4520 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 4521 T43 C2 oass.SolrIndexSearcher.<init> Opening Searcher@14fbc9df main
[junit4:junit4]   2> 4522 T43 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 4523 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@14fbc9df main{StandardDirectoryReader(segments_a:19)}
[junit4:junit4]   2> 4524 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4525 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4525 T45 C2 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4526 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 4526 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14fbc9df main{StandardDirectoryReader(segments_a:19)}
[junit4:junit4]   2> 4527 T45 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 4528 T43 C2 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 11
[junit4:junit4]   2> 4552 T43 C2 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 4553 T43 C2 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 4554 T43 C2 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 4555 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 4556 T43 C2 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 4558 T43 C2 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 4559 T43 C2 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 4576 T43 C2 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 4577 T43 C2 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 4582 T43 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_a,generation=10,filenames=[segments_a]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_b,generation=11,filenames=[_5.fnm, _5.fdt, _5_Lucene41_0.tim, segments_b, _5_Lucene41_0.tip, _5_Asserting_0.tim, _5_MockSep_0.doc, _5_MockSep_0.tii, _5_Asserting_0.doc, _5.si, _5_MockSep_0.tib, _5_Lucene41_0.doc, _5_MockSep_0.skp, _5_Asserting_0.tip, _5.fdx]
[junit4:junit4]   2> 4583 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 11[_5.fnm, _5.fdt, _5_Lucene41_0.tim, segments_b, _5_Lucene41_0.tip, _5_Asserting_0.tim, _5_MockSep_0.doc, _5_MockSep_0.tii, _5_Asserting_0.doc, _5.si, _5_MockSep_0.tib, _5_Lucene41_0.doc, _5_MockSep_0.skp, _5_Asserting_0.tip, _5.fdx]
[junit4:junit4]   2> 4583 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 4585 T43 C2 oass.SolrIndexSearcher.<init> Opening Searcher@7dbf0fd0 main
[junit4:junit4]   2> 4586 T43 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 4591 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7dbf0fd0 main{StandardDirectoryReader(segments_b:22 _5(5.0):C20)}
[junit4:junit4]   2> 4592 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4593 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4594 T45 C2 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 4594 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 4595 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7dbf0fd0 main{StandardDirectoryReader(segments_b:22 _5(5.0):C20)}
[junit4:junit4]   2> 4596 T45 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 4596 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 4597 T43 C2 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 4598 T43 C2 oashd.DocBuilder.execute Time taken = 0:0:0.43
[junit4:junit4]   2> 4598 T43 C2 UPDATE [collection1] webapp=null path=null params={indent=true&clean=true&commit=true&dataConfig=<dataConfig>+%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.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.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.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&command=full-import&synchronous=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 51
[junit4:junit4]   2> 4601 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=1 
[junit4:junit4]   2> 4609 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 4610 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 4616 T43 C2 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 4617 T43 C2 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 4618 T43 C2 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 4619 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 4621 T43 C2 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 4621 T43 C2 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 4622 T43 C2 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 4622 T43 C2 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 4626 T43 C2 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 4
[junit4:junit4]   2> 4626 T43 C2 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 9
[junit4:junit4]   2> 4627 T43 C2 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 4627 T43 C2 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 4628 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 19
[junit4:junit4]   2> 4628 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 18
[junit4:junit4]   2> 4629 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 6
[junit4:junit4]   2> 4629 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 2
[junit4:junit4]   2> 4630 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 17
[junit4:junit4]   2> 4630 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 3
[junit4:junit4]   2> 4630 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 16
[junit4:junit4]   2> 4631 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 4
[junit4:junit4]   2> 4631 T43 C2 oashd.SolrWriter.deleteDoc Deleting document: 9
[junit4:junit4]   2> 4638 T43 C2 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 4638 T43 C2 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 4639 T43 C2 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 4644 T43 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_b,generation=11,filenames=[_5.fnm, _5.fdt, _5_Lucene41_0.tim, segments_b, _5_Lucene41_0.tip, _5_Asserting_0.tim, _5_MockSep_0.doc, _5_MockSep_0.tii, _5_Asserting_0.doc, _5.si, _5_MockSep_0.tib, _5_Lucene41_0.doc, _5_MockSep_0.skp, _5_Asserting_0.tip, _5.fdx]
[junit4:junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a5f4d8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@59c691f4),segFN=segments_c,generation=12,filenames=[_5.fdt, _5_Lucene41_0.tim, _5_Lucene41_0.tip, _6.fdx, _6_Lucene41_0.tim, _6_Lucene41_0.tip, _5_MockSep_0.tii, _6_Asserting_0.tim, _5_Asserting_0.doc, _6_Asserting_0.tip, _6_MockSep_0.doc, _5_Lucene41_0.doc, _5_MockSep_0.skp, _6_MockSep_0.tii, _5.fnm, segments_c, _6_MockSep_0.tib, _5_Asserting_0.tim, _6_Lucene41_0.doc, _6_Asserting_0.doc, _5_MockSep_0.doc, _6_MockSep_0.skp, _5.si, _5_MockSep_0.tib, _5.fdx, _5_Asserting_0.tip, _6.si, _6.fnm, _6.fdt, _5_1.del]
[junit4:junit4]   2> 4645 T43 C2 oasc.SolrDeletionPolicy.updateCommits newest commit = 12[_5.fdt, _5_Lucene41_0.tim, _5_Lucene41_0.tip, _6.fdx, _6_Lucene41_0.tim, _6_Lucene41_0.tip, _5_MockSep_0.tii, _6_Asserting_0.tim, _5_Asserting_0.doc, _6_Asserting_0.tip, _6_MockSep_0.doc, _5_Lucene41_0.doc, _5_MockSep_0.skp, _6_MockSep_0.tii, _5.fnm, segments_c, _6_MockSep_0.tib, _5_Asserting_0.tim, _6_Lucene41_0.doc, _6_Asserting_0.doc, _5_MockSep_0.doc, _6_MockSep_0.skp, _5.si, _5_MockSep_0.tib, _5.fdx, _5_Asserting_0.tip, _6.si, _6.fnm, _6.fdt, _5_1.del]
[junit4:junit4]   2> 4645 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861
[junit4:junit4]   2> 4648 T43 C2 oass.SolrIndexSearcher.<init> Opening Searcher@4c33ee2b main
[junit4:junit4]   2> 4649 T43 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 4658 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4c33ee2b main{StandardDirectoryReader(segments_c:25 _5(5.0):C20/12 _6(5.0):C4)}
[junit4:junit4]   2> 4659 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4660 T45 C2 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4661 T45 C2 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 4661 T45 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 4662 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c33ee2b main{StandardDirectoryReader(segments_c:25 _5(5.0):C20/12 _6(5.0):C4)}
[junit4:junit4]   2> 4663 T45 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 4663 T43 C2 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 4664 T43 C2 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 4665 T43 C2 oashd.DocBuilder.execute Time taken = 0:0:0.45
[junit4:junit4]   2> 4665 T43 C2 UPDATE [collection1] webapp=null path=null params={indent=true&clean=false&commit=true&dataConfig=<dataConfig>+%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.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.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.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&command=delta-import&synchronous=true} {delete=[19, 18, 6, 2, 17, 3, 16, 4, 9],add=[13, 15, 14, 1005],commit=} 0 52
[junit4:junit4]   2> 4667 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=12 status=0 QTime=1 
[junit4:junit4]   2> 4673 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 4674 T43 C2 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 4675 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:1005&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 4679 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:17&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 4682 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:16&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 4685 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:19&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 4687 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:2&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4690 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:3&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4694 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:18&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 4698 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:4&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4703 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:6&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 4708 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:9&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4712 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:13&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 4730 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:14&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 4734 T43 C2 REQ [collection1] webapp=null path=null params={start=0&q=id:15&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 4738 T43 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 4739 T43 oas.SolrTestCaseJ4.tearDown ###Ending testWithSimpleTransformer
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> Fri Nov 30 17:15:52 EST 2012: Shutting down Derby engine
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> 4758 T43 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 4759 T43 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1589242951
[junit4:junit4]   2> 4759 T43 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@5b1aaec3
[junit4:junit4]   2> 4760 T43 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=11,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=137,cumulative_deletesById=16,cumulative_deletesByQuery=8,cumulative_errors=0}
[junit4:junit4]   2> 4761 T43 oasc.SolrCore.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 4761 T43 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 4761 T43 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 4762 T43 C2 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> 4763 T43 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 4763 T43 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354313747861/index
[junit4:junit4]   2> NOTE: test params are: codec=Lucene41: {timestamp=PostingsFormat(name=MockSep), id=Lucene41(blocksize=128), COUNTRY_CODES_mult_s=PostingsFormat(name=MockSep), SPORT_NAME_mult_s=PostingsFormat(name=NestedPulsing), AddAColumn_s=PostingsFormat(name=MockSep), NAME_mult_s=PostingsFormat(name=Asserting)}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=fr, timezone=America/Cayman
[junit4:junit4]   2> NOTE: Linux 3.2.0-34-generic amd64/Oracle Corporation 1.7.0_09 (64-bit)/cpus=8,threads=1,free=100704752,total=126484480
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestPlainTextEntityProcessor, TestContentStreamDataSource, TestLineEntityProcessor, TestSqlEntityProcessorDelta]
[junit4:junit4] Completed on J1 in 4.85s, 4 tests, 1 error <<< FAILURES!

[...truncated 76 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:335: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:192: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:410: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:438: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1163: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:827: There were test failures: 34 suites, 140 tests, 1 error, 3 ignored

Total time: 26 minutes 16 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 64bit/jdk1.7.0_09 -XX:+UseSerialGC
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message