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 # 2268 - Still Failing!
Date Thu, 08 Nov 2012 13:11:10 GMT
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-4.x-Linux/2268/
Java: 64bit/jdk1.6.0_37 -XX:+UseParallelGC

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

Error Message:
Expecting 9 database calls, but DIH reported 20

Stack Trace:
junit.framework.AssertionFailedError: Expecting 9 database calls, but DIH reported 20
	at __randomizedtesting.SeedInfo.seed([E94C868E4B625155:8346F70520945FE8]:0)
	at junit.framework.Assert.fail(Assert.java:50)
	at junit.framework.Assert.assertTrue(Assert.java:20)
	at org.apache.solr.handler.dataimport.AbstractDIHJdbcTestCase.complexTransform(AbstractDIHJdbcTestCase.java:129)
	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testWithComplexTransformer(TestSqlEntityProcessorDelta.java:58)
	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 10653 lines...]
[junit4:junit4] Suite: org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
[junit4:junit4]   2> 99 T10 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-1352380256072
[junit4:junit4]   2> 155 T10 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> 525 T10 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 745 T10 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4:junit4]   2> 760 T10 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 778 T10 oass.IndexSchema.readSchema Schema name=dih_test
[junit4:junit4]   2> 1169 T10 oass.IndexSchema.readSchema default search field in schema is desc
[junit4:junit4]   2> 1171 T10 oass.IndexSchema.readSchema query parser default operator is OR
[junit4:junit4]   2> 1173 T10 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1192 T10 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1193 T10 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> 1194 T10 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> 1215 T10 oasc.CoreContainer.<init> New CoreContainer 372834295
[junit4:junit4]   2> 1255 T10 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-1352380256072/
[junit4:junit4]   2> 1256 T10 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 1268 T10 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> 1269 T10 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4:junit4]   2> 1281 T10 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-1352380256072/index/
[junit4:junit4]   2> 1282 T10 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-1352380256072/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1310 T10 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-1352380256072/index forceNew:false
[junit4:junit4]   2> 1408 T10 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1408 T10 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1594 T10 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "" (default)
[junit4:junit4]   2> 1602 T10 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1608 T10 oasc.RequestHandlers.initHandlersFromConfig created /dataimport: org.apache.solr.handler.dataimport.DataImportHandler
[junit4:junit4]   2> 1609 T10 oasc.RequestHandlers.initHandlersFromConfig created /search: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1615 T10 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1647 T10 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1669 T10 oass.SolrIndexSearcher.<init> Opening Searcher@7d20b2da main
[junit4:junit4]   2> 1669 T10 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1694 T10 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1695 T10 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1717 T10 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 1717 T10 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 1718 T10 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 1718 T10 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 1719 T10 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 1719 T10 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 1720 T10 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 1720 T10 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 1721 T10 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 1731 T10 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 1919 T10 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1919 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7d20b2da main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1919 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1920 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7d20b2da main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1922 T10 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4:junit4]   2> 1939 T10 oas.SolrTestCaseJ4.setUp ###Starting testSingleEntity
[junit4:junit4]   2> ASYNC  NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@1b4b74a7
[junit4:junit4]   2> 2078 T10 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 2081 T10 C0 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 2082 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 2084 T10 C0 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 120
[junit4:junit4]   2> 2108 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 2109 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 2110 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 2112 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@6a6078e7 main
[junit4:junit4]   2> 2112 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 2115 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2116 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@6a6078e7 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 2140 T11 C0 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=22 
[junit4:junit4]   2> 2142 T11 C0 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> 2146 T11 C0 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=4 
[junit4:junit4]   2> 2146 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 2147 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6a6078e7 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 2147 T10 C0 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 41
[junit4:junit4]   2> 2381 T10 C0 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 2382 T10 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 2383 T10 C0 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 2390 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties WARNING Unable to read: dataimport.properties
[junit4:junit4]   2> 2417 T10 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 2430 T10 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 2431 T10 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 2527 T10 C0 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 2528 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 2564 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_3,generation=3,filenames=[_0.inf, _0.si, _0.pst, _0.fld, segments_3]
[junit4:junit4]   2> 2566 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 2580 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@3979c7cf main
[junit4:junit4]   2> 2581 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 2582 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2595 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3979c7cf main{StandardDirectoryReader(segments_3:5 _0(4.1):C20)}
[junit4:junit4]   2> 2596 T11 C0 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> 2597 T11 C0 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> 2599 T11 C0 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> 2599 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 2600 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3979c7cf main{StandardDirectoryReader(segments_3:5 _0(4.1):C20)}
[junit4:junit4]   2> 2601 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties WARNING Unable to read: dataimport.properties
[junit4:junit4]   2> 2608 T10 C0 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 2609 T10 C0 oashd.DocBuilder.execute Time taken = 0:0:0.207
[junit4:junit4]   2> 2610 T10 C0 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 248
[junit4:junit4]   2> 2618 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=6 
[junit4:junit4]   2> 2635 T10 C0 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 2643 T10 C0 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 2644 T10 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 2645 T10 C0 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 2646 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 2648 T10 C0 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 2649 T10 C0 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 2650 T10 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 2651 T10 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 2659 T10 C0 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 5
[junit4:junit4]   2> 2660 T10 C0 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 8
[junit4:junit4]   2> 2661 T10 C0 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 2661 T10 C0 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 2662 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 11
[junit4:junit4]   2> 2663 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 13
[junit4:junit4]   2> 2663 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 14
[junit4:junit4]   2> 2664 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 16
[junit4:junit4]   2> 2665 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 2
[junit4:junit4]   2> 2665 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 3
[junit4:junit4]   2> 2666 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 20
[junit4:junit4]   2> 2666 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 6
[junit4:junit4]   2> 2674 T10 C0 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 2675 T10 C0 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 2676 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 2735 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_3,generation=3,filenames=[_0.inf, _0.si, _0.pst, _0.fld, segments_3]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_4,generation=4,filenames=[_1.pst, _1.fld, _1.si, _1.inf, _0.inf, _0_1.liv, _0.si, _0.pst, _0.fld, segments_4]
[junit4:junit4]   2> 2736 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 4
[junit4:junit4]   2> 2740 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@455b4492 main
[junit4:junit4]   2> 2741 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 2742 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2743 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@455b4492 main{StandardDirectoryReader(segments_4:8 _0(4.1):C20/13 _1(4.1):C5)}
[junit4:junit4]   2> 2744 T11 C0 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> 2744 T11 C0 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> 2745 T11 C0 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> 2746 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 2746 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@455b4492 main{StandardDirectoryReader(segments_4:8 _0(4.1):C20/13 _1(4.1):C5)}
[junit4:junit4]   2> 2747 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 2748 T10 C0 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 2748 T10 C0 oashd.DocBuilder.execute Time taken = 0:0:0.100
[junit4:junit4]   2> 2749 T10 C0 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"+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=[11, 13, 14, 16, 2, 3, 20, 6],add=[9, 12, 17, 5, 7],commit=} 0 109
[junit4:junit4]   2> 2751 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=12 status=0 QTime=1 
[junit4:junit4]   2> 2759 T10 C0 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 2764 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:16&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=4 
[junit4:junit4]   2> 2768 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:2&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 2772 T10 C0 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> 2776 T10 C0 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> 2780 T10 C0 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> 2784 T10 C0 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> 2788 T10 C0 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> 2792 T10 C0 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> 2796 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:17&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 2802 T10 C0 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> 2809 T10 C0 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> 2815 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:9&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 2821 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:12&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 2836 T10 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> 2837 T10 oas.SolrTestCaseJ4.tearDown ###Ending testSingleEntity
[junit4:junit4]   2> 2896 T10 oas.SolrTestCaseJ4.setUp ###Starting testChildEntities
[junit4:junit4]   2> 2902 T10 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 2903 T10 C0 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4:junit4]   2> 2910 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 2911 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_4,generation=4,filenames=[_1.pst, _1.fld, _1.si, _1.inf, _0.inf, _0_1.liv, _0.si, _0.pst, _0.fld, segments_4]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 2912 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 5
[junit4:junit4]   2> 2914 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@77c30993 main
[junit4:junit4]   2> 2914 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 2915 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2916 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@77c30993 main{StandardDirectoryReader(segments_5:9)}
[junit4:junit4]   2> 2916 T11 C0 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> 2917 T11 C0 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> 2918 T11 C0 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> 2918 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 2919 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@77c30993 main{StandardDirectoryReader(segments_5:9)}
[junit4:junit4]   2> 2920 T10 C0 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4:junit4]   2> 2940 T10 C0 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 2941 T10 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 2941 T10 C0 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 2942 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 2944 T10 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 2945 T10 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 2946 T10 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 2969 T10 C0 oashd.JdbcDataSource$1.call Creating a connection for entity Sports with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 2970 T10 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 3014 T10 C0 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 3015 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 3020 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_6,generation=6,filenames=[_2.si, _2.pst, _2.fld, _2.inf, segments_6]
[junit4:junit4]   2> 3021 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 6
[junit4:junit4]   2> 3024 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@233f99af main
[junit4:junit4]   2> 3025 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 3026 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 3035 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@233f99af main{StandardDirectoryReader(segments_6:12 _2(4.1):C20)}
[junit4:junit4]   2> 3038 T11 C0 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> 3039 T11 C0 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> 3039 T11 C0 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> 3040 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 3040 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@233f99af main{StandardDirectoryReader(segments_6:12 _2(4.1):C20)}
[junit4:junit4]   2> 3041 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3042 T10 C0 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 3043 T10 C0 oashd.DocBuilder.execute Time taken = 0:0:0.100
[junit4:junit4]   2> 3044 T10 C0 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"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"+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 110
[junit4:junit4]   2> 3047 T10 C0 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> 3069 T10 C0 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=3 
[junit4:junit4]   2> 3090 T10 C0 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=7 
[junit4:junit4]   2> 3104 T10 C0 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=6 
[junit4:junit4]   2> 3119 T10 C0 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 3121 T10 C0 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 3132 T10 C0 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 3133 T10 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 3134 T10 C0 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 3134 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3136 T10 C0 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 3136 T10 C0 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: Sports
[junit4:junit4]   2> 3137 T10 C0 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: Sports rows obtained : 0
[junit4:junit4]   2> 3137 T10 C0 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: Sports rows obtained : 0
[junit4:junit4]   2> 3138 T10 C0 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: Sports
[junit4:junit4]   2> 3138 T10 C0 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 3139 T10 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 3139 T10 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 3142 T10 C0 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 3144 T10 C0 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 10
[junit4:junit4]   2> 3145 T10 C0 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 4
[junit4:junit4]   2> 3146 T10 C0 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 3146 T10 C0 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 3147 T10 C0 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 3147 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 18
[junit4:junit4]   2> 3148 T10 C0 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 3149 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 7
[junit4:junit4]   2> 3149 T10 C0 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 3150 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 2
[junit4:junit4]   2> 3150 T10 C0 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 3151 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 9
[junit4:junit4]   2> 3152 T10 C0 oashd.JdbcDataSource$1.call Creating a connection for entity Sports with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 3152 T10 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 3169 T10 C0 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 3170 T10 C0 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 3170 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 3177 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_6,generation=6,filenames=[_2.si, _2.pst, _2.fld, _2.inf, segments_6]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_7,generation=7,filenames=[_3.fld, _2.si, _2.pst, _3.inf, _2.fld, segments_7, _2.inf, _2_1.liv, _3.si, _3.pst]
[junit4:junit4]   2> 3177 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 7
[junit4:junit4]   2> 3180 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@2f8fc9ba main
[junit4:junit4]   2> 3180 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 3181 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 3196 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2f8fc9ba main{StandardDirectoryReader(segments_7:15 _2(4.1):C20/12 _3(4.1):C10)}
[junit4:junit4]   2> 3197 T11 C0 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> 3198 T11 C0 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> 3199 T11 C0 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> 3199 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 3200 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2f8fc9ba main{StandardDirectoryReader(segments_7:15 _2(4.1):C20/12 _3(4.1):C10)}
[junit4:junit4]   2> 3200 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3201 T10 C0 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 3202 T10 C0 oashd.DocBuilder.execute Time taken = 0:0:0.67
[junit4:junit4]   2> 3202 T10 C0 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"+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"+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=[18, 7, 2, 9],add=[1, 1001, 6, 13, 16, 1015, 20, 15, 5, 8],commit=} 0 76
[junit4:junit4]   2> 3204 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=18 status=0 QTime=1 
[junit4:junit4]   2> 3216 T10 C0 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> 3230 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:1001&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 3234 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:1015&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 3238 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:2&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 3243 T10 C0 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> 3249 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:7&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 3253 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:9&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 3259 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:1&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 3265 T10 C0 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> 3271 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:20&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 3277 T10 C0 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> 3283 T10 C0 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> 3288 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:8&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 3302 T10 C0 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> 3308 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:15&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 3313 T10 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> 3314 T10 oas.SolrTestCaseJ4.tearDown ###Ending testChildEntities
[junit4:junit4]   2> 3329 T10 oas.SolrTestCaseJ4.setUp ###Starting testWithComplexTransformer
[junit4:junit4]   2> 3334 T10 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 3335 T10 C0 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 3344 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 3345 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_7,generation=7,filenames=[_3.fld, _2.si, _2.pst, _3.inf, _2.fld, segments_7, _2.inf, _2_1.liv, _3.si, _3.pst]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 3346 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 8
[junit4:junit4]   2> 3348 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@dec3c6d main
[junit4:junit4]   2> 3348 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 3349 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 3350 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@dec3c6d main{StandardDirectoryReader(segments_8:16)}
[junit4:junit4]   2> 3351 T11 C0 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> 3352 T11 C0 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> 3353 T11 C0 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> 3353 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 3354 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@dec3c6d main{StandardDirectoryReader(segments_8:16)}
[junit4:junit4]   2> 3355 T10 C0 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 12
[junit4:junit4]   2> 3367 T10 C0 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 3368 T10 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 3369 T10 C0 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 3369 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3370 T10 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 3371 T10 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 3372 T10 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 3434 T10 C0 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 3435 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 3443 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_9,generation=9,filenames=[_4.pst, segments_9, _4.fld, _4.si, _4.inf]
[junit4:junit4]   2> 3444 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 9
[junit4:junit4]   2> 3448 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@3219ee8a main
[junit4:junit4]   2> 3449 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 3452 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 3475 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3219ee8a main{StandardDirectoryReader(segments_9:19 _4(4.1):C60)}
[junit4:junit4]   2> 3476 T11 C0 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> 3477 T11 C0 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> 3478 T11 C0 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> 3478 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 3479 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3219ee8a main{StandardDirectoryReader(segments_9:19 _4(4.1):C60)}
[junit4:junit4]   2> 3484 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3485 T10 C0 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 3486 T10 C0 oashd.DocBuilder.execute Time taken = 0:0:0.116
[junit4:junit4]   2> 3487 T10 C0 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 124
[junit4:junit4]   2> 3598 T10 C0 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=60} hits=60 status=0 QTime=110 
[junit4:junit4]   2> 3641 T10 C0 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=16 
[junit4:junit4]   2> 3653 T10 C0 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=3 
[junit4:junit4]   2> 3664 T10 C0 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> 3674 T10 C0 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 3675 T10 C0 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 3684 T10 C0 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 3685 T10 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 3686 T10 C0 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 3687 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3688 T10 C0 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 3688 T10 C0 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 3689 T10 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 3690 T10 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 3695 T10 C0 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 18
[junit4:junit4]   2> 3696 T10 C0 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 4
[junit4:junit4]   2> 3696 T10 C0 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 3697 T10 C0 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 3697 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 12
[junit4:junit4]   2> 3698 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 1
[junit4:junit4]   2> 3698 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 20
[junit4:junit4]   2> 3699 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 7
[junit4:junit4]   2> 3741 T10 C0 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 3742 T10 C0 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 3742 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 3762 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_9,generation=9,filenames=[_4.pst, segments_9, _4.fld, _4.si, _4.inf]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_a,generation=10,filenames=[_5.si, _4.pst, _5.inf, _4.fld, segments_a, _4_1.liv, _5.pst, _4.si, _4.inf, _5.fld]
[junit4:junit4]   2> 3763 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 10
[junit4:junit4]   2> 3767 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@69fc9f88 main
[junit4:junit4]   2> 3768 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 3768 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 3796 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@69fc9f88 main{StandardDirectoryReader(segments_a:22 _4(4.1):C60/52 _5(4.1):C54)}
[junit4:junit4]   2> 3796 T11 C0 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> 3797 T11 C0 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> 3797 T11 C0 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> 3798 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 3798 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@69fc9f88 main{StandardDirectoryReader(segments_a:22 _4(4.1):C60/52 _5(4.1):C54)}
[junit4:junit4]   2> 3799 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3800 T10 C0 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 3801 T10 C0 oashd.DocBuilder.execute Time taken = 0:0:0.113
[junit4:junit4]   2> 3801 T10 C0 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=[12, 1, 20, 7],add=[17, TripleThreat-1-17, TripleThreat-2-17, 16, TripleThreat-1-16, TripleThreat-2-16, 19, TripleThreat-1-19, TripleThreat-2-19, 18, ... (54 adds)],commit=} 0 122
[junit4:junit4]   2> 3805 T10 C0 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=54} hits=62 status=0 QTime=2 
[junit4:junit4]   2> 3821 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:TripleThreat-1-*&qt=standard&rows=20&version=2.2} hits=22 status=0 QTime=1 
[junit4:junit4]   2> 3828 T10 C0 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> 3839 T10 C0 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> 3846 T10 C0 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 3847 T10 C0 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 3848 T10 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> 3849 T10 oas.SolrTestCaseJ4.tearDown ###Ending testWithComplexTransformer
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSqlEntityProcessorDelta -Dtests.method=testWithComplexTransformer -Dtests.seed=E94C868E4B625155 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=iw_IL -Dtests.timezone=Asia/Qatar -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE 0.58s J1 | TestSqlEntityProcessorDelta.testWithComplexTransformer <<<
[junit4:junit4]    > Throwable #1: junit.framework.AssertionFailedError: Expecting 9 database calls, but DIH reported 20
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([E94C868E4B625155:8346F70520945FE8]:0)
[junit4:junit4]    > 	at junit.framework.Assert.fail(Assert.java:50)
[junit4:junit4]    > 	at junit.framework.Assert.assertTrue(Assert.java:20)
[junit4:junit4]    > 	at org.apache.solr.handler.dataimport.AbstractDIHJdbcTestCase.complexTransform(AbstractDIHJdbcTestCase.java:129)
[junit4:junit4]    > 	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testWithComplexTransformer(TestSqlEntityProcessorDelta.java:58)
[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> 3904 T10 oas.SolrTestCaseJ4.setUp ###Starting testWithSimpleTransformer
[junit4:junit4]   2> 3910 T10 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 3911 T10 C0 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 3917 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 3918 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_a,generation=10,filenames=[_5.si, _4.pst, _5.inf, _4.fld, segments_a, _4_1.liv, _5.pst, _4.si, _4.inf, _5.fld]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_b,generation=11,filenames=[segments_b]
[junit4:junit4]   2> 3919 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 11
[junit4:junit4]   2> 3920 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@31923ca5 main
[junit4:junit4]   2> 3920 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 3921 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 3922 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@31923ca5 main{StandardDirectoryReader(segments_b:23)}
[junit4:junit4]   2> 3923 T11 C0 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> 3924 T11 C0 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> 3925 T11 C0 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> 3925 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 3926 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@31923ca5 main{StandardDirectoryReader(segments_b:23)}
[junit4:junit4]   2> 3927 T10 C0 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4:junit4]   2> 3935 T10 C0 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 3935 T10 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 3936 T10 C0 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 3936 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3937 T10 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 3938 T10 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 3938 T10 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 3953 T10 C0 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 3953 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 3956 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_b,generation=11,filenames=[segments_b]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_c,generation=12,filenames=[_6.pst, segments_c, _6.fld, _6.si, _6.inf]
[junit4:junit4]   2> 3956 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 12
[junit4:junit4]   2> 3958 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@22fe135d main
[junit4:junit4]   2> 3959 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 3959 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 3970 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@22fe135d main{StandardDirectoryReader(segments_c:26 _6(4.1):C20)}
[junit4:junit4]   2> 3970 T11 C0 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> 3971 T11 C0 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> 3972 T11 C0 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> 3972 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 3972 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@22fe135d main{StandardDirectoryReader(segments_c:26 _6(4.1):C20)}
[junit4:junit4]   2> 3973 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3974 T10 C0 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 3974 T10 C0 oashd.DocBuilder.execute Time taken = 0:0:0.37
[junit4:junit4]   2> 3975 T10 C0 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 43
[junit4:junit4]   2> 3976 T10 C0 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> 3985 T10 C0 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 3991 T10 C0 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 3992 T10 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 3993 T10 C0 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 3994 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 3995 T10 C0 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 3996 T10 C0 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 3997 T10 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 3999 T10 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 4018 T10 C0 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 0
[junit4:junit4]   2> 4019 T10 C0 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 2
[junit4:junit4]   2> 4020 T10 C0 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 4020 T10 C0 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 4021 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 19
[junit4:junit4]   2> 4022 T10 C0 oashd.SolrWriter.deleteDoc Deleting document: 16
[junit4:junit4]   2> 4023 T10 C0 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 4023 T10 C0 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 4024 T10 C0 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 4047 T10 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_c,generation=12,filenames=[_6.pst, segments_c, _6.fld, _6.si, _6.inf]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@33238785 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c2d0479),segFN=segments_d,generation=13,filenames=[_6.pst, segments_d, _6.fld, _6.si, _6.inf, _6_1.liv]
[junit4:junit4]   2> 4048 T10 C0 oasc.SolrDeletionPolicy.updateCommits newest commit = 13
[junit4:junit4]   2> 4050 T10 C0 oass.SolrIndexSearcher.<init> Opening Searcher@3eb8f71 main
[junit4:junit4]   2> 4051 T10 C0 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 4052 T10 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 4060 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3eb8f71 main{StandardDirectoryReader(segments_d:27 _6(4.1):C20/2)}
[junit4:junit4]   2> 4061 T11 C0 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> 4062 T11 C0 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> 4063 T11 C0 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> 4063 T11 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 4064 T11 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3eb8f71 main{StandardDirectoryReader(segments_d:27 _6(4.1):C20/2)}
[junit4:junit4]   2> 4076 T10 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 4077 T10 C0 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 4078 T10 C0 oashd.DocBuilder.execute Time taken = 0:0:0.83
[junit4:junit4]   2> 4078 T10 C0 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=[19, 16],commit=} 0 90
[junit4:junit4]   2> 4081 T10 C0 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=1 
[junit4:junit4]   2> 4101 T10 C0 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 4102 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:16&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 4107 T10 C0 REQ [collection1] webapp=null path=null params={start=0&q=id:19&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 4111 T10 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> 4112 T10 oas.SolrTestCaseJ4.tearDown ###Ending testWithSimpleTransformer
[junit4:junit4]   2> 4127 T10 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 4127 T10 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=372834295
[junit4:junit4]   2> 4128 T10 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1b4b74a7
[junit4:junit4]   2> 4129 T10 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=189,cumulative_deletesById=18,cumulative_deletesByQuery=8,cumulative_errors=0}
[junit4:junit4]   2> 4129 T10 oasc.SolrCore.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 4130 T10 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 4130 T10 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 4132 T10 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> NOTE: test params are: codec=SimpleText, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=iw_IL, timezone=Asia/Qatar
[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=97463928,total=118489088
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestSqlEntityProcessorDelta]
[junit4:junit4] Completed on J1 in 4.80s, 4 tests, 1 failure <<< FAILURES!

[...truncated 103 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: 27 minutes 14 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 64bit/jdk1.6.0_37 -XX:+UseParallelGC
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message