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 (64bit/jdk1.6.0_37) - Build # 2270 - Failure!
Date Thu, 08 Nov 2012 15:33:03 GMT
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-4.x-Linux/2270/
Java: 64bit/jdk1.6.0_37 -XX:+UseConcMarkSweepGC

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

Error Message:


Stack Trace:
junit.framework.AssertionFailedError
	at __randomizedtesting.SeedInfo.seed([7ABC0EB25D0EA317:1403722E32E34C94]:0)
	at junit.framework.Assert.fail(Assert.java:48)
	at junit.framework.Assert.assertTrue(Assert.java:20)
	at junit.framework.Assert.assertTrue(Assert.java:27)
	at org.apache.solr.handler.dataimport.AbstractDIHJdbcTestCase.singleEntity(AbstractDIHJdbcTestCase.java:103)
	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:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	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:662)




Build Log:
[...truncated 10800 lines...]
[junit4:junit4] Suite: org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
[junit4:junit4]   2> 2 T57 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-1352388776022
[junit4:junit4]   2> 2 T57 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> 44 T57 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 114 T57 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4:junit4]   2> 115 T57 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 129 T57 oass.IndexSchema.readSchema Schema name=dih_test
[junit4:junit4]   2> 212 T57 oass.IndexSchema.readSchema default search field in schema is desc
[junit4:junit4]   2> 213 T57 oass.IndexSchema.readSchema query parser default operator is OR
[junit4:junit4]   2> 214 T57 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 216 T57 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 216 T57 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> 216 T57 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> 224 T57 oasc.CoreContainer.<init> New CoreContainer 1102757339
[junit4:junit4]   2> 224 T57 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-1352388776022/
[junit4:junit4]   2> 225 T57 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 225 T57 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> 225 T57 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4:junit4]   2> 226 T57 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-1352388776022/index/
[junit4:junit4]   2> 226 T57 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-1352388776022/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 227 T57 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-1352388776022/index forceNew:false
[junit4:junit4]   2> 229 T57 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 229 T57 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 230 T57 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "" (default)
[junit4:junit4]   2> 231 T57 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 231 T57 oasc.RequestHandlers.initHandlersFromConfig created /dataimport: org.apache.solr.handler.dataimport.DataImportHandler
[junit4:junit4]   2> 232 T57 oasc.RequestHandlers.initHandlersFromConfig created /search: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 232 T57 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 234 T57 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 237 T57 oass.SolrIndexSearcher.<init> Opening Searcher@6da21389 main
[junit4:junit4]   2> 238 T57 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 238 T57 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 239 T57 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 239 T57 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 240 T57 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 240 T57 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 240 T57 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 241 T57 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 241 T57 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 241 T57 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 242 T57 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 242 T57 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 242 T57 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 248 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@6da21389 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 248 T57 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 250 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 251 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6da21389 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 252 T57 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4:junit4]   2> 258 T57 oas.SolrTestCaseJ4.setUp ###Starting testWithSimpleTransformer
[junit4:junit4]   2> ASYNC  NEW_CORE C3 name=collection1 org.apache.solr.core.SolrCore@46c9220
[junit4:junit4]   2> 264 T57 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 266 T57 C3 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 267 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 268 T57 C3 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 5
[junit4:junit4]   2> 281 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 282 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 283 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 284 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@57cae5b7 main
[junit4:junit4]   2> 285 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 286 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@57cae5b7 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 286 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 287 T58 C3 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> 287 T58 C3 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> 288 T58 C3 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> 289 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 289 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@57cae5b7 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 290 T57 C3 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 9
[junit4:junit4]   2> 485 T57 C3 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 486 T57 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 486 T57 C3 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 487 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 498 T57 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 501 T57 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 502 T57 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 540 T57 C3 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 541 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 549 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_3,generation=3,filenames=[_0_Lucene40_0.tim, _0.fnm, _0_Lucene40_0.frq, _0.fdx, _0.si, _0.fdt, segments_3, _0_Lucene40_0.tip]
[junit4:junit4]   2> 549 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 555 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@4283df14 main
[junit4:junit4]   2> 555 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 556 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 556 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4283df14 main{StandardDirectoryReader(segments_3:5 _0(4.1):C20)}
[junit4:junit4]   2> 557 T58 C3 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> 557 T58 C3 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> 558 T58 C3 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> 558 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 559 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4283df14 main{StandardDirectoryReader(segments_3:5 _0(4.1):C20)}
[junit4:junit4]   2> 559 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 560 T57 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 561 T57 C3 oashd.DocBuilder.execute Time taken = 0:0:0.74
[junit4:junit4]   2> 561 T57 C3 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<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=full-import&synchronous=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 79
[junit4:junit4]   2> 568 T57 C3 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=6 
[junit4:junit4]   2> 578 T57 C3 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 587 T57 C3 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 587 T57 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 588 T57 C3 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 589 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 590 T57 C3 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 590 T57 C3 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 591 T57 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 592 T57 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 602 T57 C3 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 7
[junit4:junit4]   2> 602 T57 C3 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 3
[junit4:junit4]   2> 603 T57 C3 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 603 T57 C3 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 604 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 18
[junit4:junit4]   2> 604 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 11
[junit4:junit4]   2> 605 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 4
[junit4:junit4]   2> 612 T57 C3 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 613 T57 C3 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 613 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 634 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_3,generation=3,filenames=[_0_Lucene40_0.tim, _0.fnm, _0_Lucene40_0.frq, _0.fdx, _0.si, _0.fdt, segments_3, _0_Lucene40_0.tip]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_4,generation=4,filenames=[_1_Lucene40_0.tim, _0_Lucene40_0.tim, _0.fnm, _1_Lucene40_0.frq, _0_1.del, _1.fnm, _1_Lucene40_0.tip, _0_Lucene40_0.tip, _1.fdx, _0_Lucene40_0.frq, _1.fdt, _1.si, _0.fdx, _0.si, _0.fdt, segments_4]
[junit4:junit4]   2> 634 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 4
[junit4:junit4]   2> 640 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@203ba002 main
[junit4:junit4]   2> 641 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 642 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 644 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@203ba002 main{StandardDirectoryReader(segments_4:8 _0(4.1):C20/9 _1(4.1):C7)}
[junit4:junit4]   2> 644 T58 C3 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> 645 T58 C3 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> 645 T58 C3 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> 646 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 646 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@203ba002 main{StandardDirectoryReader(segments_4:8 _0(4.1):C20/9 _1(4.1):C7)}
[junit4:junit4]   2> 647 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 648 T57 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 648 T57 C3 oashd.DocBuilder.execute Time taken = 0:0:0.59
[junit4:junit4]   2> 649 T57 C3 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<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=delta-import&synchronous=true} {delete=[18, 11, 4],add=[19, 6, 12, 2, 16, 1003, 10],commit=} 0 66
[junit4:junit4]   2> 652 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=18 status=0 QTime=2 
[junit4:junit4]   2> 665 T57 C3 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 667 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:1003&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 673 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:18&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 678 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:4&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 683 T57 C3 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> 688 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:16&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 696 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:2&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 701 T57 C3 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> 706 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:6&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 711 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:10&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 716 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:12&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 720 T57 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> 721 T57 oas.SolrTestCaseJ4.tearDown ###Ending testWithSimpleTransformer
[junit4:junit4]   2> 726 T57 oas.SolrTestCaseJ4.setUp ###Starting testChildEntities
[junit4:junit4]   2> 731 T57 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 732 T57 C3 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 740 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 742 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_4,generation=4,filenames=[_1_Lucene40_0.tim, _0_Lucene40_0.tim, _0.fnm, _1_Lucene40_0.frq, _0_1.del, _1.fnm, _1_Lucene40_0.tip, _0_Lucene40_0.tip, _1.fdx, _0_Lucene40_0.frq, _1.fdt, _1.si, _0.fdx, _0.si, _0.fdt, segments_4]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 744 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 5
[junit4:junit4]   2> 746 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@5999ae9c main
[junit4:junit4]   2> 746 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 747 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 747 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5999ae9c main{StandardDirectoryReader(segments_5:9)}
[junit4:junit4]   2> 748 T58 C3 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> 749 T58 C3 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> 750 T58 C3 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> 750 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 751 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5999ae9c main{StandardDirectoryReader(segments_5:9)}
[junit4:junit4]   2> 751 T57 C3 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 11
[junit4:junit4]   2> 765 T57 C3 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 766 T57 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 766 T57 C3 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 767 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 767 T57 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 768 T57 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 769 T57 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 770 T57 C3 oashd.JdbcDataSource$1.call Creating a connection for entity Sports with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 770 T57 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 805 T57 C3 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 806 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 812 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_6,generation=6,filenames=[_2.si, _2_Lucene40_0.tip, _2_Lucene40_0.frq, _2.fdt, _2_Lucene40_0.tim, _2.fdx, segments_6, _2.fnm]
[junit4:junit4]   2> 813 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 6
[junit4:junit4]   2> 821 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@7a0d637d main
[junit4:junit4]   2> 822 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 823 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 827 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7a0d637d main{StandardDirectoryReader(segments_6:12 _2(4.1):C20)}
[junit4:junit4]   2> 828 T58 C3 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> 828 T58 C3 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> 829 T58 C3 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> 830 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 830 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7a0d637d main{StandardDirectoryReader(segments_6:12 _2(4.1):C20)}
[junit4:junit4]   2> 831 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 832 T57 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 832 T57 C3 oashd.DocBuilder.execute Time taken = 0:0:0.65
[junit4:junit4]   2> 833 T57 C3 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<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}'+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a<entity+name%3D"Sports"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+newColumnName%3D"sportsAdded_s"+newColumnValue%3D"sport_added"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+ID,+SPORT_NAME+FROM+PEOPLE_SPORTS+WHERE+DELETED+!%3D+'Y'+AND+PERSON_ID%3D'${People.ID}'+ORDER+BY+ID"+>+%0a<field+column%3D"SPORT_NAME"+name%3D"SPORT_NAME_mult_s"+/>+%0a<field+column%3D"id"+name%3D"SPORT_ID_mult_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=full-import&synchronous=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 71
[junit4:junit4]   2> 836 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=2 
[junit4:junit4]   2> 851 T57 C3 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> 864 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=SPORT_NAME_mult_s:Sailing&qt=standard&rows=20&version=2.2} hits=2 status=0 QTime=1 
[junit4:junit4]   2> 870 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=NAME_mult_s:Michael&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 881 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=sportsAdded_s:sport_added&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=1 
[junit4:junit4]   2> 893 T57 C3 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 895 T57 C3 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=1 
[junit4:junit4]   2> 903 T57 C3 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 904 T57 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 905 T57 C3 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 905 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 906 T57 C3 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 907 T57 C3 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: Sports
[junit4:junit4]   2> 908 T57 C3 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: Sports rows obtained : 0
[junit4:junit4]   2> 908 T57 C3 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: Sports rows obtained : 0
[junit4:junit4]   2> 909 T57 C3 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: Sports
[junit4:junit4]   2> 909 T57 C3 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 910 T57 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 911 T57 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 914 T57 C3 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 917 T57 C3 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 6
[junit4:junit4]   2> 917 T57 C3 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 4
[junit4:junit4]   2> 918 T57 C3 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 919 T57 C3 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 919 T57 C3 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 920 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 8
[junit4:junit4]   2> 920 T57 C3 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 921 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 9
[junit4:junit4]   2> 922 T57 C3 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 922 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 12
[junit4:junit4]   2> 923 T57 C3 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 924 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 4
[junit4:junit4]   2> 925 T57 C3 oashd.JdbcDataSource$1.call Creating a connection for entity Sports with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 926 T57 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 940 T57 C3 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 941 T57 C3 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 941 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 947 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_6,generation=6,filenames=[_2.si, _2_Lucene40_0.tip, _2_Lucene40_0.frq, _2.fdt, _2_Lucene40_0.tim, _2.fdx, segments_6, _2.fnm]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_7,generation=7,filenames=[_2.si, _3_Lucene40_0.tip, _3_Lucene40_0.tim, _2.fdt, _3.fdt, _3.fnm, _2.fdx, _2.fnm, _3.fdx, _2_Lucene40_0.tip, segments_7, _3_Lucene40_0.frq, _2_Lucene40_0.frq, _3.si, _2_Lucene40_0.tim, _2_1.del]
[junit4:junit4]   2> 947 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 7
[junit4:junit4]   2> 950 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@77b31c23 main
[junit4:junit4]   2> 950 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 951 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 957 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@77b31c23 main{StandardDirectoryReader(segments_7:15 _2(4.1):C20/9 _3(4.1):C6)}
[junit4:junit4]   2> 957 T58 C3 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> 958 T58 C3 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> 959 T58 C3 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> 959 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 959 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@77b31c23 main{StandardDirectoryReader(segments_7:15 _2(4.1):C20/9 _3(4.1):C6)}
[junit4:junit4]   2> 960 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 960 T57 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 961 T57 C3 oashd.DocBuilder.execute Time taken = 0:0:0.55
[junit4:junit4]   2> 961 T57 C3 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<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}'+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a<entity+name%3D"Sports"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+newColumnName%3D"sportsAdded_s"+newColumnValue%3D"sport_added"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+ID,+SPORT_NAME+FROM+PEOPLE_SPORTS+WHERE+DELETED+!%3D+'Y'+AND+PERSON_ID%3D'${People.ID}'+ORDER+BY+ID"+>+%0a<field+column%3D"SPORT_NAME"+name%3D"SPORT_NAME_mult_s"+/>+%0a<field+column%3D"id"+name%3D"SPORT_ID_mult_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=delta-import&synchronous=true} {delete=[8, 9, 12, 4],add=[1012, 13, 17, 2, 5, 6],commit=} 0 62
[junit4:junit4]   2> 963 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=17 status=0 QTime=1 
[junit4:junit4]   2> 972 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=NAME_mult_s:Michael&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 979 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:1012&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 982 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:4&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 985 T57 C3 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> 988 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:9&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 990 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:12&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 993 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:17&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 997 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:2&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1002 T57 C3 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> 1010 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:6&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1015 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:13&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 1019 T57 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> 1019 T57 oas.SolrTestCaseJ4.tearDown ###Ending testChildEntities
[junit4:junit4]   2> 1024 T57 oas.SolrTestCaseJ4.setUp ###Starting testWithComplexTransformer
[junit4:junit4]   2> 1028 T57 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1029 T57 C3 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 1036 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1037 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_7,generation=7,filenames=[_2.si, _3_Lucene40_0.tip, _3_Lucene40_0.tim, _2.fdt, _3.fdt, _3.fnm, _2.fdx, _2.fnm, _3.fdx, _2_Lucene40_0.tip, segments_7, _3_Lucene40_0.frq, _2_Lucene40_0.frq, _3.si, _2_Lucene40_0.tim, _2_1.del]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 1037 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 8
[junit4:junit4]   2> 1038 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@682f8c99 main
[junit4:junit4]   2> 1039 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1039 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1040 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@682f8c99 main{StandardDirectoryReader(segments_8:16)}
[junit4:junit4]   2> 1041 T58 C3 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> 1043 T58 C3 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> 1044 T58 C3 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> 1045 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1045 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@682f8c99 main{StandardDirectoryReader(segments_8:16)}
[junit4:junit4]   2> 1046 T57 C3 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 11
[junit4:junit4]   2> 1054 T57 C3 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1055 T57 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1055 T57 C3 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 1055 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1056 T57 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1057 T57 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1058 T57 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1118 T57 C3 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1119 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1127 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_9,generation=9,filenames=[_4.fdx, segments_9, _4_Lucene40_0.frq, _4_Lucene40_0.tip, _4.fnm, _4.si, _4.fdt, _4_Lucene40_0.tim]
[junit4:junit4]   2> 1128 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 9
[junit4:junit4]   2> 1180 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@141d19 main
[junit4:junit4]   2> 1181 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1181 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1186 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@141d19 main{StandardDirectoryReader(segments_9:19 _4(4.1):C60)}
[junit4:junit4]   2> 1187 T58 C3 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> 1188 T58 C3 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> 1189 T58 C3 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> 1189 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1190 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@141d19 main{StandardDirectoryReader(segments_9:19 _4(4.1):C60)}
[junit4:junit4]   2> 1190 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1191 T57 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1192 T57 C3 oashd.DocBuilder.execute Time taken = 0:0:0.136
[junit4:junit4]   2> 1192 T57 C3 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<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+transformer%3D"TripleThreatTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=full-import&synchronous=true} {deleteByQuery=*:*,add=[1, TripleThreat-1-1, TripleThreat-2-1, 2, TripleThreat-1-2, TripleThreat-2-2, 3, TripleThreat-1-3, TripleThreat-2-3, 4, ... (60 adds)],commit=} 0 140
[junit4:junit4]   2> 1247 T57 C3 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=60} hits=60 status=0 QTime=54 
[junit4:junit4]   2> 1271 T57 C3 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=5 
[junit4:junit4]   2> 1278 T57 C3 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> 1285 T57 C3 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> 1290 T57 C3 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1291 T57 C3 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1298 T57 C3 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1299 T57 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1299 T57 C3 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 1300 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1300 T57 C3 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 1301 T57 C3 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 1301 T57 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1302 T57 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1305 T57 C3 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 4
[junit4:junit4]   2> 1306 T57 C3 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 6
[junit4:junit4]   2> 1306 T57 C3 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 1307 T57 C3 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 1307 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 8
[junit4:junit4]   2> 1307 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 10
[junit4:junit4]   2> 1308 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 12
[junit4:junit4]   2> 1308 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 17
[junit4:junit4]   2> 1309 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 3
[junit4:junit4]   2> 1309 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 4
[junit4:junit4]   2> 1319 T57 C3 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 1320 T57 C3 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1320 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1326 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_9,generation=9,filenames=[_4.fdx, segments_9, _4_Lucene40_0.frq, _4_Lucene40_0.tip, _4.fnm, _4.si, _4.fdt, _4_Lucene40_0.tim]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_a,generation=10,filenames=[_5.fnm, _5_Lucene40_0.frq, _5.fdt, segments_a, _4.fnm, _4.fdt, _4.si, _4.fdx, _5.si, _5_Lucene40_0.tim, _5_Lucene40_0.tip, _4_Lucene40_0.frq, _5.fdx, _4_Lucene40_0.tip, _4_1.del, _4_Lucene40_0.tim]
[junit4:junit4]   2> 1326 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 10
[junit4:junit4]   2> 1328 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@780324ff main
[junit4:junit4]   2> 1329 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1329 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1340 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@780324ff main{StandardDirectoryReader(segments_a:22 _4(4.1):C60/15 _5(4.1):C12)}
[junit4:junit4]   2> 1341 T58 C3 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> 1341 T58 C3 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> 1342 T58 C3 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> 1343 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1343 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@780324ff main{StandardDirectoryReader(segments_a:22 _4(4.1):C60/15 _5(4.1):C12)}
[junit4:junit4]   2> 1344 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1345 T57 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1345 T57 C3 oashd.DocBuilder.execute Time taken = 0:0:0.45
[junit4:junit4]   2> 1346 T57 C3 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<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+transformer%3D"TripleThreatTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=delta-import&synchronous=true} {delete=[8, 10, 12, 17, 3, 4],add=[1016, TripleThreat-1-1016, TripleThreat-2-1016, 18, TripleThreat-1-18, TripleThreat-2-18, 6, TripleThreat-1-6, TripleThreat-2-6, 7, ... (12 adds)],commit=} 0 53
[junit4:junit4]   2> 1348 T57 C3 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=45} hits=57 status=0 QTime=1 
[junit4:junit4]   2> 1363 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:TripleThreat-1-*&qt=standard&rows=20&version=2.2} hits=21 status=0 QTime=1 
[junit4:junit4]   2> 1371 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:TripleThreat-2-*&qt=standard&rows=20&version=2.2} hits=21 status=0 QTime=1 
[junit4:junit4]   2> 1381 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=21 status=0 QTime=1 
[junit4:junit4]   2> 1388 T57 C3 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1389 T57 C3 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1391 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:1016&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 1395 T57 C3 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> 1399 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:3&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1402 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:4&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1406 T57 C3 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> 1409 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:10&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1413 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:12&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1416 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:18&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1421 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:6&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1425 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=id:7&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 1428 T57 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> 1429 T57 oas.SolrTestCaseJ4.tearDown ###Ending testWithComplexTransformer
[junit4:junit4]   2> 1439 T57 oas.SolrTestCaseJ4.setUp ###Starting testSingleEntity
[junit4:junit4]   2> 1442 T57 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1443 T57 C3 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 1448 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1448 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_a,generation=10,filenames=[_5.fnm, _5_Lucene40_0.frq, _5.fdt, segments_a, _4.fnm, _4.fdt, _4.si, _4.fdx, _5.si, _5_Lucene40_0.tim, _5_Lucene40_0.tip, _4_Lucene40_0.frq, _5.fdx, _4_Lucene40_0.tip, _4_1.del, _4_Lucene40_0.tim]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_b,generation=11,filenames=[segments_b]
[junit4:junit4]   2> 1449 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 11
[junit4:junit4]   2> 1450 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@64f007ad main
[junit4:junit4]   2> 1450 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1453 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1454 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@64f007ad main{StandardDirectoryReader(segments_b:23)}
[junit4:junit4]   2> 1455 T58 C3 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> 1455 T58 C3 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> 1456 T58 C3 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> 1456 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1456 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@64f007ad main{StandardDirectoryReader(segments_b:23)}
[junit4:junit4]   2> 1457 T57 C3 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4:junit4]   2> 1465 T57 C3 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1466 T57 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1466 T57 C3 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 1467 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1467 T57 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1468 T57 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1469 T57 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1481 T57 C3 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1481 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1485 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_b,generation=11,filenames=[segments_b]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_c,generation=12,filenames=[segments_c, _6_Lucene40_0.tim, _6_Lucene40_0.tip, _6.fdx, _6.si, _6.fnm, _6.fdt, _6_Lucene40_0.frq]
[junit4:junit4]   2> 1485 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 12
[junit4:junit4]   2> 1487 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@442b7fc2 main
[junit4:junit4]   2> 1488 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1488 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1496 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@442b7fc2 main{StandardDirectoryReader(segments_c:26 _6(4.1):C20)}
[junit4:junit4]   2> 1497 T58 C3 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> 1498 T58 C3 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> 1499 T58 C3 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> 1499 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1499 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@442b7fc2 main{StandardDirectoryReader(segments_c:26 _6(4.1):C20)}
[junit4:junit4]   2> 1500 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1501 T57 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1501 T57 C3 oashd.DocBuilder.execute Time taken = 0:0:0.34
[junit4:junit4]   2> 1502 T57 C3 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<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"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 39
[junit4:junit4]   2> 1503 T57 C3 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> 1509 T57 C3 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1513 T57 C3 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1513 T57 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1513 T57 C3 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 1514 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1515 T57 C3 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 1516 T57 C3 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 1517 T57 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1517 T57 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1522 T57 C3 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 1524 T57 C3 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 19
[junit4:junit4]   2> 1524 T57 C3 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 2
[junit4:junit4]   2> 1525 T57 C3 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 1526 T57 C3 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 1526 T57 C3 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 1527 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 10
[junit4:junit4]   2> 1528 T57 C3 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 1528 T57 C3 oashd.SolrWriter.deleteDoc Deleting document: 7
[junit4:junit4]   2> 1545 T57 C3 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 1545 T57 C3 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1545 T57 C3 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1551 T57 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_c,generation=12,filenames=[segments_c, _6_Lucene40_0.tim, _6_Lucene40_0.tip, _6.fdx, _6.si, _6.fnm, _6.fdt, _6_Lucene40_0.frq]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b069693 lockFactory=org.apache.lucene.store.NativeFSLockFactory@381172c5),segFN=segments_d,generation=13,filenames=[_7.fnm, segments_d, _7_Lucene40_0.frq, _7.si, _7.fdx, _7_Lucene40_0.tim, _7.fdt, _7_Lucene40_0.tip]
[junit4:junit4]   2> 1551 T57 C3 oasc.SolrDeletionPolicy.updateCommits newest commit = 13
[junit4:junit4]   2> 1553 T57 C3 oass.SolrIndexSearcher.<init> Opening Searcher@121a2cc7 main
[junit4:junit4]   2> 1554 T57 C3 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1554 T57 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1562 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@121a2cc7 main{StandardDirectoryReader(segments_d:30 _7(4.1):C19)}
[junit4:junit4]   2> 1563 T58 C3 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> 1564 T58 C3 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> 1565 T58 C3 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> 1565 T58 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1565 T58 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@121a2cc7 main{StandardDirectoryReader(segments_d:30 _7(4.1):C19)}
[junit4:junit4]   2> 1566 T57 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1567 T57 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1568 T57 C3 oashd.DocBuilder.execute Time taken = 0:0:0.53
[junit4:junit4]   2> 1568 T57 C3 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<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} {delete=[10, 7],add=[17, 16, 19, 18, 20, 1007, 8, 9, 11, 12, ... (19 adds)],commit=} 0 57
[junit4:junit4]   2> 1570 T57 C3 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=19 status=0 QTime=1 
[junit4:junit4]   2> 1575 T57 C3 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1576 T57 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> 1577 T57 oas.SolrTestCaseJ4.tearDown ###Ending testSingleEntity
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSqlEntityProcessorDelta -Dtests.method=testSingleEntity -Dtests.seed=7ABC0EB25D0EA317 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hi_IN -Dtests.timezone=Asia/Katmandu -Dtests.file.encoding=UTF-8
[junit4:junit4] FAILURE 0.19s J1 | TestSqlEntityProcessorDelta.testSingleEntity <<<
[junit4:junit4]    > Throwable #1: junit.framework.AssertionFailedError
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([7ABC0EB25D0EA317:1403722E32E34C94]:0)
[junit4:junit4]    > 	at junit.framework.Assert.fail(Assert.java:48)
[junit4:junit4]    > 	at junit.framework.Assert.assertTrue(Assert.java:20)
[junit4:junit4]    > 	at junit.framework.Assert.assertTrue(Assert.java:27)
[junit4:junit4]    > 	at org.apache.solr.handler.dataimport.AbstractDIHJdbcTestCase.singleEntity(AbstractDIHJdbcTestCase.java:103)
[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:39)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:597)
[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:662)
[junit4:junit4]   2> 1624 T57 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 1625 T57 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1102757339
[junit4:junit4]   2> 1625 T57 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@46c9220
[junit4:junit4]   2> 1625 T57 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=12,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=164,cumulative_deletesById=15,cumulative_deletesByQuery=8,cumulative_errors=0}
[junit4:junit4]   2> 1626 T57 oasc.SolrCore.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 1626 T57 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 1626 T57 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 1627 T57 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=hi_IN, timezone=Asia/Katmandu
[junit4:junit4]   2> NOTE: Linux 3.2.0-32-generic amd64/Sun Microsystems Inc. 1.6.0_37 (64-bit)/cpus=8,threads=1,free=67651712,total=85000192
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestErrorHandling, TestXPathEntityProcessor, TestContentStreamDataSource, TestLineEntityProcessor, TestJdbcDataSource, TestScriptTransformer, TestPlainTextEntityProcessor, TestDocBuilder, TestXPathRecordReader, TestSqlEntityProcessorDelta]
[junit4:junit4] Completed on J1 in 1.66s, 4 tests, 1 failure <<< FAILURES!

[...truncated 67 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/lucene/module-build.xml:61: 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: 33 suites, 138 tests, 1 failure, 5 ignored

Total time: 30 minutes 18 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 64bit/jdk1.6.0_37 -XX:+UseConcMarkSweepGC
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message