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-4.x-Linux (32bit/jdk1.7.0_09) - Build # 2977 - Failure!
Date Fri, 30 Nov 2012 23:50:51 GMT
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-4.x-Linux/2977/
Java: 32bit/jdk1.7.0_09 -client -XX:+UseConcMarkSweepGC

1 tests failed.
REGRESSION:  org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testSingleEntity

Error Message:
Exception during query

Stack Trace:
java.lang.RuntimeException: Exception during query
	at __randomizedtesting.SeedInfo.seed([291CB6F81D6789EB:47A3CA64728A6668]:0)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:513)
	at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.singleEntity(AbstractSqlEntityProcessorTestCase.java:66)
	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testSingleEntity(TestSqlEntityProcessorDelta.java:44)
	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='16']
	xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">0</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</date></doc></result>
</response>

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




Build Log:
[...truncated 11907 lines...]
[junit4:junit4] Suite: org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
[junit4:junit4]   2> Fri Nov 30 23:50:42 WET 2012 Thread[SUITE-TestSqlEntityProcessorDelta-seed#[291CB6F81D6789EB]-worker,5,TGRP-TestSqlEntityProcessorDelta] java.lang.ClassNotFoundException: DerbyUtil
[junit4:junit4]   2> 9 T66 oas.SolrTestCaseJ4.initCore ####initCore
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354319442684
[junit4:junit4]   2> 9 T66 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/collection1/'
[junit4:junit4]   2> 71 T66 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 142 T66 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4:junit4]   2> 142 T66 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 147 T66 oass.IndexSchema.readSchema Schema name=dih_test
[junit4:junit4]   2> 224 T66 oass.IndexSchema.readSchema default search field in schema is desc
[junit4:junit4]   2> 227 T66 oass.IndexSchema.readSchema query parser default operator is OR
[junit4:junit4]   2> 228 T66 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 229 T66 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 230 T66 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr
[junit4:junit4]   2> 230 T66 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/'
[junit4:junit4]   2> 239 T66 oasc.CoreContainer.<init> New CoreContainer 31906048
[junit4:junit4]   2> 240 T66 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354319442684/
[junit4:junit4]   2> 240 T66 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 241 T66 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> 241 T66 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4:junit4]   2> 242 T66 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354319442684/index/
[junit4:junit4]   2> 242 T66 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354319442684/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 243 T66 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1354319442684/index forceNew:false
[junit4:junit4]   2> 244 T66 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 244 T66 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 245 T66 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "" (default)
[junit4:junit4]   2> 246 T66 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 247 T66 oasc.RequestHandlers.initHandlersFromConfig created /dataimport: org.apache.solr.handler.dataimport.DataImportHandler
[junit4:junit4]   2> 248 T66 oasc.RequestHandlers.initHandlersFromConfig created /search: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 249 T66 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 253 T66 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 259 T66 oass.SolrIndexSearcher.<init> Opening Searcher@140e766 main
[junit4:junit4]   2> 259 T66 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 260 T66 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 260 T66 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 261 T66 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 261 T66 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 262 T66 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 262 T66 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 263 T66 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 264 T66 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 264 T66 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 265 T66 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 265 T66 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 266 T66 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 270 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@140e766 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 270 T66 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 270 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 271 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@140e766 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 272 T66 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4:junit4]   2> 275 T66 oas.SolrTestCaseJ4.setUp ###Starting testWithSimpleTransformer
[junit4:junit4]   2> ASYNC  NEW_CORE C4 name=collection1 org.apache.solr.core.SolrCore@1b10feb
[junit4:junit4]   2> 279 T66 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 280 T66 C4 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 281 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 281 T66 C4 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 3
[junit4:junit4]   2> 302 T66 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 302 T66 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 303 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 304 T66 C4 oass.SolrIndexSearcher.<init> Opening Searcher@1db9526 main
[junit4:junit4]   2> 304 T66 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 304 T66 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 304 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1db9526 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 305 T68 C4 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> 305 T68 C4 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> 306 T68 C4 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> 306 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 306 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1db9526 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 307 T66 C4 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 6
[junit4:junit4]   2> 324 T66 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 325 T66 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 326 T66 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 326 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 327 T66 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 328 T66 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 329 T66 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 354 T66 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 355 T66 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 357 T66 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_3,generation=3,filenames=[_0.tis, _0.fnm, _0.tii, _0.frq, _0.fdx, _0.si, _0.fdt, segments_3]
[junit4:junit4]   2> 358 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 359 T66 C4 oass.SolrIndexSearcher.<init> Opening Searcher@1af6c5a main
[junit4:junit4]   2> 359 T66 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 360 T66 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 360 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1af6c5a main{StandardDirectoryReader(segments_3:5 _0(4.1):C20)}
[junit4:junit4]   2> 361 T68 C4 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> 361 T68 C4 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> 362 T68 C4 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> 362 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 362 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1af6c5a main{StandardDirectoryReader(segments_3:5 _0(4.1):C20)}
[junit4:junit4]   2> 363 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 364 T66 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 364 T66 C4 oashd.DocBuilder.execute Time taken = 0:0:0.37
[junit4:junit4]   2> 364 T66 C4 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 42
[junit4:junit4]   2> 369 T66 C4 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> 375 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 376 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 383 T66 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 384 T66 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 384 T66 C4 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 385 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 386 T66 C4 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 386 T66 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 386 T66 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 387 T66 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 389 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 390 T66 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 5
[junit4:junit4]   2> 390 T66 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 7
[junit4:junit4]   2> 391 T66 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 391 T66 C4 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 392 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 392 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 1
[junit4:junit4]   2> 392 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 393 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 6
[junit4:junit4]   2> 393 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 393 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 13
[junit4:junit4]   2> 394 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 394 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 17
[junit4:junit4]   2> 394 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 395 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 16
[junit4:junit4]   2> 395 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 395 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 14
[junit4:junit4]   2> 396 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 396 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 8
[junit4:junit4]   2> 400 T66 C4 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 401 T66 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 401 T66 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 417 T66 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_3,generation=3,filenames=[_0.tis, _0.fnm, _0.tii, _0.frq, _0.fdx, _0.si, _0.fdt, segments_3]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_4,generation=4,filenames=[_0.tis, _0.fnm, _1.tis, _1.frq, _0_1.del, _1.fnm, _1.fdx, _0.tii, _1.fdt, _1.si, _0.frq, _1.tii, _0.fdx, _0.si, _0.fdt, segments_4]
[junit4:junit4]   2> 418 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 4
[junit4:junit4]   2> 422 T66 C4 oass.SolrIndexSearcher.<init> Opening Searcher@331323 main
[junit4:junit4]   2> 422 T66 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 423 T66 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 425 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@331323 main{StandardDirectoryReader(segments_4:8 _0(4.1):C20/10 _1(4.1):C5)}
[junit4:junit4]   2> 425 T68 C4 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> 426 T68 C4 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> 426 T68 C4 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> 426 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 426 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@331323 main{StandardDirectoryReader(segments_4:8 _0(4.1):C20/10 _1(4.1):C5)}
[junit4:junit4]   2> 427 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 428 T66 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 428 T66 C4 oashd.DocBuilder.execute Time taken = 0:0:0.43
[junit4:junit4]   2> 429 T66 C4 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"People.ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.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=[1, 6, 13, 17, 16, 14, 8],add=[19, 18, 1019, 10, 1011],commit=} 0 50
[junit4:junit4]   2> 430 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=15 status=0 QTime=0 
[junit4:junit4]   2> 434 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 435 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 437 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:1019&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=2 
[junit4:junit4]   2> 440 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:1011&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 443 T66 C4 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> 446 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:1&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 454 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:16&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=6 
[junit4:junit4]   2> 457 T66 C4 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> 460 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:8&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 463 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:13&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 466 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:14&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 469 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:19&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 473 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:18&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 487 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:10&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=2 
[junit4:junit4]   2> 490 T66 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 491 T66 oas.SolrTestCaseJ4.tearDown ###Ending testWithSimpleTransformer
[junit4:junit4]   2> 495 T66 oas.SolrTestCaseJ4.setUp ###Starting testChildEntities
[junit4:junit4]   2> 498 T66 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 499 T66 C4 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 519 T66 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 520 T66 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_4,generation=4,filenames=[_0.tis, _0.fnm, _1.tis, _1.frq, _0_1.del, _1.fnm, _1.fdx, _0.tii, _1.fdt, _1.si, _0.frq, _1.tii, _0.fdx, _0.si, _0.fdt, segments_4]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 520 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 5
[junit4:junit4]   2> 522 T66 C4 oass.SolrIndexSearcher.<init> Opening Searcher@4c01cd main
[junit4:junit4]   2> 522 T66 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 522 T66 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 523 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4c01cd main{StandardDirectoryReader(segments_5:9)}
[junit4:junit4]   2> 523 T68 C4 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> 524 T68 C4 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> 524 T68 C4 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> 524 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 525 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c01cd main{StandardDirectoryReader(segments_5:9)}
[junit4:junit4]   2> 525 T66 C4 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 6
[junit4:junit4]   2> 540 T66 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 540 T66 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 540 T66 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 541 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 541 T66 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 542 T66 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 543 T66 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 544 T66 C4 oashd.JdbcDataSource$1.call Creating a connection for entity Countries with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 544 T66 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 560 T66 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 560 T66 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 564 T66 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_6,generation=6,filenames=[_2.si, _2.tis, _2.fdt, _2.frq, _2.tii, _2.fdx, segments_6, _2.fnm]
[junit4:junit4]   2> 564 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 6
[junit4:junit4]   2> 566 T66 C4 oass.SolrIndexSearcher.<init> Opening Searcher@16db786 main
[junit4:junit4]   2> 566 T66 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 567 T66 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 571 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@16db786 main{StandardDirectoryReader(segments_6:12 _2(4.1):C20)}
[junit4:junit4]   2> 571 T68 C4 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> 572 T68 C4 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> 572 T68 C4 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> 572 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 572 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16db786 main{StandardDirectoryReader(segments_6:12 _2(4.1):C20)}
[junit4:junit4]   2> 573 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 574 T66 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 574 T66 C4 oashd.DocBuilder.execute Time taken = 0:0:0.33
[junit4:junit4]   2> 574 T66 C4 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"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"Countries"+pk%3D"CODE"+dataSource%3D"hsqldb"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+CODE,+COUNTRY_NAME+FROM+COUNTRIES+WHERE+DELETED+!%3D+'Y'+AND+CODE%3D'${People.COUNTRY_CODE}'+"+>+%0a<field+column%3D"CODE"+name%3D"COUNTRY_CODE_s"+/>+%0a<field+column%3D"COUNTRY_NAME"+name%3D"COUNTRY_NAME_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=full-import&synchronous=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 36
[junit4:junit4]   2> 578 T66 C4 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> 584 T66 C4 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=0 
[junit4:junit4]   2> 591 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=NAME_mult_s:Jayden&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 596 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=COUNTRY_CODES_mult_s:NR&qt=standard&rows=20&version=2.2} hits=2 status=0 QTime=1 
[junit4:junit4]   2> 599 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 600 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 603 T66 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 603 T66 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 603 T66 C4 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 604 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 605 T66 C4 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 605 T66 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: Countries
[junit4:junit4]   2> 605 T66 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: Countries rows obtained : 0
[junit4:junit4]   2> 606 T66 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: Countries rows obtained : 0
[junit4:junit4]   2> 606 T66 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: Countries
[junit4:junit4]   2> 606 T66 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 607 T66 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 613 T66 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 616 T66 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 4
[junit4:junit4]   2> 616 T66 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
[junit4:junit4]   2> 617 T66 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 617 T66 C4 oashd.JdbcDataSource$1.call Creating a connection for entity Countries with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 618 T66 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 622 T66 C4 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 623 T66 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 623 T66 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 626 T66 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_6,generation=6,filenames=[_2.si, _2.tis, _2.fdt, _2.frq, _2.tii, _2.fdx, segments_6, _2.fnm]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_7,generation=7,filenames=[_2.si, _3.frq, _3.tii, _2.frq, _2.fdt, _3.fdt, _3.fnm, _2.tii, _2.fdx, _2.fnm, _3.fdx, segments_7, _2.tis, _3.si, _2_1.del, _3.tis]
[junit4:junit4]   2> 626 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 7
[junit4:junit4]   2> 628 T66 C4 oass.SolrIndexSearcher.<init> Opening Searcher@2633f4 main
[junit4:junit4]   2> 628 T66 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 629 T66 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 638 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2633f4 main{StandardDirectoryReader(segments_7:15 _2(4.1):C20/4 _3(4.1):C4)}
[junit4:junit4]   2> 639 T68 C4 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> 639 T68 C4 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> 640 T68 C4 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> 640 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 640 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2633f4 main{StandardDirectoryReader(segments_7:15 _2(4.1):C20/4 _3(4.1):C4)}
[junit4:junit4]   2> 641 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 641 T66 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 642 T66 C4 oashd.DocBuilder.execute Time taken = 0:0:0.38
[junit4:junit4]   2> 642 T66 C4 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"Countries"+pk%3D"CODE"+dataSource%3D"hsqldb"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+CODE,+COUNTRY_NAME+FROM+COUNTRIES+WHERE+DELETED+!%3D+'Y'+AND+CODE%3D'${People.COUNTRY_CODE}'+"+>+%0a<field+column%3D"CODE"+name%3D"COUNTRY_CODE_s"+/>+%0a<field+column%3D"COUNTRY_NAME"+name%3D"COUNTRY_NAME_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=delta-import&synchronous=true} {add=[18, 1, 16, 5],commit=} 0 41
[junit4:junit4]   2> 644 T66 C4 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> 648 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=NAME_mult_s:Jayden&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 652 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=COUNTRY_CODES_mult_s:NR&qt=standard&rows=20&version=2.2} hits=2 status=0 QTime=0 
[junit4:junit4]   2> 667 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=COUNTRY_CODE_s:NZ&qt=standard&rows=20&version=2.2} hits=2 status=0 QTime=4 
[junit4:junit4]   2> 674 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=COUNTRY_CODE_s:NC&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=3 
[junit4:junit4]   2> 681 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=COUNTRY_CODE_s:NO&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=2 
[junit4:junit4]   2> 686 T66 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 687 T66 oas.SolrTestCaseJ4.tearDown ###Ending testChildEntities
[junit4:junit4]   2> 692 T66 oas.SolrTestCaseJ4.setUp ###Starting testWithComplexTransformer
[junit4:junit4]   2> 706 T66 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 707 T66 C4 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 712 T66 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 713 T66 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_7,generation=7,filenames=[_2.si, _3.frq, _3.tii, _2.frq, _2.fdt, _3.fdt, _3.fnm, _2.tii, _2.fdx, _2.fnm, _3.fdx, segments_7, _2.tis, _3.si, _2_1.del, _3.tis]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 713 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 8
[junit4:junit4]   2> 714 T66 C4 oass.SolrIndexSearcher.<init> Opening Searcher@f5a51 main
[junit4:junit4]   2> 714 T66 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 715 T66 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 716 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@f5a51 main{StandardDirectoryReader(segments_8:16)}
[junit4:junit4]   2> 717 T68 C4 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> 717 T68 C4 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> 718 T68 C4 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> 718 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 718 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f5a51 main{StandardDirectoryReader(segments_8:16)}
[junit4:junit4]   2> 719 T66 C4 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 7
[junit4:junit4]   2> 728 T66 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 728 T66 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 729 T66 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 729 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 730 T66 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 741 T66 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 741 T66 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 782 T66 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 782 T66 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 786 T66 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_9,generation=9,filenames=[_4.fdx, segments_9, _4.tii, _4.frq, _4.fnm, _4.si, _4.fdt, _4.tis]
[junit4:junit4]   2> 786 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 9
[junit4:junit4]   2> 840 T66 C4 oass.SolrIndexSearcher.<init> Opening Searcher@472108 main
[junit4:junit4]   2> 841 T66 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 841 T66 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 846 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@472108 main{StandardDirectoryReader(segments_9:19 _4(4.1):C60)}
[junit4:junit4]   2> 846 T68 C4 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> 847 T68 C4 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> 847 T68 C4 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> 847 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 847 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@472108 main{StandardDirectoryReader(segments_9:19 _4(4.1):C60)}
[junit4:junit4]   2> 848 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 849 T66 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 849 T66 C4 oashd.DocBuilder.execute Time taken = 0:0:0.119
[junit4:junit4]   2> 849 T66 C4 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"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 123
[junit4:junit4]   2> 906 T66 C4 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=60} hits=60 status=0 QTime=55 
[junit4:junit4]   2> 913 T66 C4 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=1 
[junit4:junit4]   2> 922 T66 C4 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> 930 T66 C4 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=5 
[junit4:junit4]   2> 933 T66 C4 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=0 
[junit4:junit4]   2> 937 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=1 
[junit4:junit4]   2> 937 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 943 T66 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 944 T66 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 944 T66 C4 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 945 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 946 T66 C4 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 947 T66 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 947 T66 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 948 T66 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 950 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 951 T66 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 6
[junit4:junit4]   2> 952 T66 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 8
[junit4:junit4]   2> 952 T66 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 953 T66 C4 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 953 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 954 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 8
[junit4:junit4]   2> 954 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 955 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 10
[junit4:junit4]   2> 955 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 956 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 11
[junit4:junit4]   2> 956 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 957 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 15
[junit4:junit4]   2> 957 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 958 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 19
[junit4:junit4]   2> 958 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 959 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 18
[junit4:junit4]   2> 959 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 959 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 20
[junit4:junit4]   2> 960 T66 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 960 T66 C4 oashd.SolrWriter.deleteDoc Deleting document: 6
[junit4:junit4]   2> 972 T66 C4 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 973 T66 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 973 T66 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 976 T66 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_9,generation=9,filenames=[_4.fdx, segments_9, _4.tii, _4.frq, _4.fnm, _4.si, _4.fdt, _4.tis]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_a,generation=10,filenames=[_4.tii, _5.fnm, _5.fdt, segments_a, _4.fnm, _5.frq, _4.fdt, _4.si, _5.tii, _4.fdx, _5.si, _4.frq, _5.tis, _5.fdx, _4_1.del, _4.tis]
[junit4:junit4]   2> 977 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 10
[junit4:junit4]   2> 1029 T66 C4 oass.SolrIndexSearcher.<init> Opening Searcher@23e42c main
[junit4:junit4]   2> 1029 T66 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1030 T66 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1049 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@23e42c main{StandardDirectoryReader(segments_a:22 _4(4.1):C60/20 _5(4.1):C18)}
[junit4:junit4]   2> 1050 T68 C4 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> 1050 T68 C4 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> 1051 T68 C4 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> 1051 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1051 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@23e42c main{StandardDirectoryReader(segments_a:22 _4(4.1):C60/20 _5(4.1):C18)}
[junit4:junit4]   2> 1054 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1055 T66 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1055 T66 C4 oashd.DocBuilder.execute Time taken = 0:0:0.109
[junit4:junit4]   2> 1056 T66 C4 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"People.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=[8, 10, 11, 15, 19, 18, 20, 6],add=[1009, TripleThreat-1-1009, TripleThreat-2-1009, 16, TripleThreat-1-16, TripleThreat-2-16, 1, TripleThreat-1-1, TripleThreat-2-1, 1018, ... (18 adds)],commit=} 0 117
[junit4:junit4]   2> 1057 T66 C4 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=42} hits=58 status=0 QTime=0 
[junit4:junit4]   2> 1062 T66 C4 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=0 
[junit4:junit4]   2> 1075 T66 C4 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=1 
[junit4:junit4]   2> 1078 T66 C4 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=0 
[junit4:junit4]   2> 1080 T66 C4 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=0 
[junit4:junit4]   2> 1083 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=1 
[junit4:junit4]   2> 1085 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1087 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:1018&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 1091 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:1009&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=2 
[junit4:junit4]   2> 1093 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:19&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1095 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:18&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1098 T66 C4 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> 1100 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:6&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1102 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:8&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1104 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:10&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1109 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:11&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1112 T66 C4 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> 1114 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:16&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1117 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:1&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1122 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:4&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=2 
[junit4:junit4]   2> 1127 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:5&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 1130 T66 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 1131 T66 oas.SolrTestCaseJ4.tearDown ###Ending testWithComplexTransformer
[junit4:junit4]   2> 1140 T66 oas.SolrTestCaseJ4.setUp ###Starting testSingleEntity
[junit4:junit4]   2> 1143 T66 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1144 T66 C4 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 1153 T66 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1154 T66 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_a,generation=10,filenames=[_4.tii, _5.fnm, _5.fdt, segments_a, _4.fnm, _5.frq, _4.fdt, _4.si, _5.tii, _4.fdx, _5.si, _4.frq, _5.tis, _5.fdx, _4_1.del, _4.tis]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_b,generation=11,filenames=[segments_b]
[junit4:junit4]   2> 1155 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 11
[junit4:junit4]   2> 1156 T66 C4 oass.SolrIndexSearcher.<init> Opening Searcher@3d7135 main
[junit4:junit4]   2> 1156 T66 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1156 T66 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1157 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3d7135 main{StandardDirectoryReader(segments_b:23)}
[junit4:junit4]   2> 1158 T68 C4 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> 1158 T68 C4 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> 1159 T68 C4 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> 1159 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1159 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d7135 main{StandardDirectoryReader(segments_b:23)}
[junit4:junit4]   2> 1160 T66 C4 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 7
[junit4:junit4]   2> 1175 T66 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1176 T66 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1176 T66 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 1177 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1177 T66 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1178 T66 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1178 T66 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1185 T66 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1185 T66 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1187 T66 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_b,generation=11,filenames=[segments_b]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0b4e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1511f96),segFN=segments_c,generation=12,filenames=[_6.tis, segments_c, _6.frq, _6.fdx, _6.tii, _6.si, _6.fnm, _6.fdt]
[junit4:junit4]   2> 1188 T66 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 12
[junit4:junit4]   2> 1189 T66 C4 oass.SolrIndexSearcher.<init> Opening Searcher@14f13b8 main
[junit4:junit4]   2> 1189 T66 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1190 T66 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1198 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@14f13b8 main{StandardDirectoryReader(segments_c:26 _6(4.1):C20)}
[junit4:junit4]   2> 1199 T68 C4 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> 1200 T68 C4 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> 1200 T68 C4 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> 1200 T68 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1201 T68 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14f13b8 main{StandardDirectoryReader(segments_c:26 _6(4.1):C20)}
[junit4:junit4]   2> 1201 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1202 T66 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1202 T66 C4 oashd.DocBuilder.execute Time taken = 0:0:0.25
[junit4:junit4]   2> 1203 T66 C4 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"hsqldb"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.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 29
[junit4:junit4]   2> 1206 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=0 
[junit4:junit4]   2> 1209 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1209 T66 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1212 T66 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1213 T66 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1213 T66 C4 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 1213 T66 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1214 T66 C4 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 1215 T66 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 1215 T66 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1216 T66 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1218 T66 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 0
[junit4:junit4]   2> 1218 T66 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
[junit4:junit4]   2> 1219 T66 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 1219 T66 C4 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 1219 T66 C4 oashd.DocBuilder.execute Time taken = 0:0:0.5
[junit4:junit4]   2> 1220 T66 C4 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"People.ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.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} {} 0 9
[junit4:junit4]   2> 1221 T66 C4 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=0 
[junit4:junit4]   2> 1225 T66 oas.SolrTestCaseJ4.assertQ SEVERE REQUEST FAILED: xpath=//*[@numFound='16']
[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">0</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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> 1226 T66 oasc.SolrException.log SEVERE REQUEST FAILED: start=0&q=*:*&qt=standard&rows=20&version=2.2:java.lang.RuntimeException: REQUEST FAILED: xpath=//*[@numFound='16']
[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">0</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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:506)
[junit4:junit4]   2> 		at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.singleEntity(AbstractSqlEntityProcessorTestCase.java:66)
[junit4:junit4]   2> 		at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testSingleEntity(TestSqlEntityProcessorDelta.java:44)
[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> 1228 T66 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 1228 T66 oas.SolrTestCaseJ4.tearDown ###Ending testSingleEntity
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSqlEntityProcessorDelta -Dtests.method=testSingleEntity -Dtests.seed=291CB6F81D6789EB -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ca_ES -Dtests.timezone=Atlantic/Faroe -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR   0.14s J1 | TestSqlEntityProcessorDelta.testSingleEntity <<<
[junit4:junit4]    > Throwable #1: java.lang.RuntimeException: Exception during query
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([291CB6F81D6789EB:47A3CA64728A6668]:0)
[junit4:junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:513)
[junit4:junit4]    > 	at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.singleEntity(AbstractSqlEntityProcessorTestCase.java:66)
[junit4:junit4]    > 	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testSingleEntity(TestSqlEntityProcessorDelta.java:44)
[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='16']
[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">0</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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><date name="timestamp">2012-11-30T23:50:43.849Z</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:506)
[junit4:junit4]    > 	... 42 more
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> Fri Nov 30 23:50:43 WET 2012: Shutting down Derby engine
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> 1294 T66 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 1294 T66 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=31906048
[junit4:junit4]   2> 1294 T66 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1b10feb
[junit4:junit4]   2> 1295 T66 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=147,cumulative_deletesById=15,cumulative_deletesByQuery=8,cumulative_errors=0}
[junit4:junit4]   2> 1295 T66 oasc.SolrCore.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 1296 T66 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 1296 T66 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 1297 T66 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> NOTE: test params are: codec=Lucene3x, sim=DefaultSimilarity, locale=ca_ES, timezone=Atlantic/Faroe
[junit4:junit4]   2> NOTE: Linux 3.2.0-34-generic i386/Oracle Corporation 1.7.0_09 (32-bit)/cpus=8,threads=1,free=6256408,total=20463616
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestXPathRecordReader, TestVariableResolverEndToEnd, TestEphemeralCache, TestTemplateTransformer, TestXPathEntityProcessor, TestDateFormatTransformer, TestRegexTransformer, TestDocBuilder, TestVariableResolver, TestLineEntityProcessor, TestContentStreamDataSource, TestSqlEntityProcessorDelta]
[junit4:junit4] Completed on J1 in 1.33s, 4 tests, 1 error <<< FAILURES!

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

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



Mime
View raw message