lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@sd-datasolutions.de>
Subject [JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.7.0_09) - Build # 2975 - Failure!
Date Fri, 30 Nov 2012 21:49:04 GMT
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-4.x-Linux/2975/
Java: 32bit/jdk1.7.0_09 -server -XX:+UseConcMarkSweepGC

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

Error Message:
Expecting 6 database calls, but DIH reported 23

Stack Trace:
junit.framework.AssertionFailedError: Expecting 6 database calls, but DIH reported 23
	at __randomizedtesting.SeedInfo.seed([FA2A49314043F780:902038BA2BB5F93D]:0)
	at junit.framework.Assert.fail(Assert.java:50)
	at junit.framework.Assert.assertTrue(Assert.java:20)
	at org.apache.solr.handler.dataimport.AbstractSqlEntityProcessorTestCase.complexTransform(AbstractSqlEntityProcessorTestCase.java:111)
	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:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:722)




Build Log:
[...truncated 11913 lines...]
[junit4:junit4] Suite: org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
[junit4:junit4]   2> Sat Dec 01 04:18:54 MMT 2012 Thread[SUITE-TestSqlEntityProcessorDelta-seed#[FA2A49314043F780]-worker,5,TGRP-TestSqlEntityProcessorDelta] java.lang.ClassNotFoundException: DerbyUtil
[junit4:junit4]   2> 10 T38 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-1354312134989
[junit4:junit4]   2> 11 T38 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> 69 T38 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 116 T38 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4:junit4]   2> 117 T38 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 126 T38 oass.IndexSchema.readSchema Schema name=dih_test
[junit4:junit4]   2> 193 T38 oass.IndexSchema.readSchema default search field in schema is desc
[junit4:junit4]   2> 194 T38 oass.IndexSchema.readSchema query parser default operator is OR
[junit4:junit4]   2> 195 T38 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 197 T38 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 197 T38 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> 197 T38 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> 204 T38 oasc.CoreContainer.<init> New CoreContainer 33065800
[junit4:junit4]   2> 205 T38 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-1354312134989/
[junit4:junit4]   2> 205 T38 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 206 T38 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> 206 T38 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4:junit4]   2> 206 T38 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-1354312134989/index/
[junit4:junit4]   2> 207 T38 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-1354312134989/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 207 T38 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-1354312134989/index forceNew:false
[junit4:junit4]   2> 209 T38 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 209 T38 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 210 T38 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "" (default)
[junit4:junit4]   2> 211 T38 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 212 T38 oasc.RequestHandlers.initHandlersFromConfig created /dataimport: org.apache.solr.handler.dataimport.DataImportHandler
[junit4:junit4]   2> 213 T38 oasc.RequestHandlers.initHandlersFromConfig created /search: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 217 T38 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 222 T38 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 227 T38 oass.SolrIndexSearcher.<init> Opening Searcher@174ef21 main
[junit4:junit4]   2> 227 T38 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 228 T38 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 228 T38 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 229 T38 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 230 T38 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 230 T38 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 231 T38 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 231 T38 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 232 T38 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 232 T38 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 233 T38 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 233 T38 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 234 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 240 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@174ef21 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 240 T38 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 241 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 241 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@174ef21 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 243 T38 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4:junit4]   2> 250 T38 oas.SolrTestCaseJ4.setUp ###Starting testSingleEntity
[junit4:junit4]   2> ASYNC  NEW_CORE C4 name=collection1 org.apache.solr.core.SolrCore@161dd83
[junit4:junit4]   2> 254 T38 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 257 T38 C4 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 257 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 258 T38 C4 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 4
[junit4:junit4]   2> 270 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 271 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 271 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 272 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@779b1b main
[junit4:junit4]   2> 273 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 274 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@779b1b main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 274 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 275 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 275 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 276 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 277 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 277 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@779b1b main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 278 T38 C4 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 9
[junit4:junit4]   2> 299 T38 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 300 T38 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 301 T38 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 301 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 303 T38 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 304 T38 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 304 T38 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 317 T38 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 318 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 321 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.frq, _0.tim, _0.fdx, _0.si, _0.tip, _0.fdt, segments_3]
[junit4:junit4]   2> 321 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 323 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@e922a1 main
[junit4:junit4]   2> 323 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 324 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 324 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@e922a1 main{StandardDirectoryReader(segments_3:5 _0(4.1):C20)}
[junit4:junit4]   2> 325 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 325 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 326 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 326 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 326 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e922a1 main{StandardDirectoryReader(segments_3:5 _0(4.1):C20)}
[junit4:junit4]   2> 327 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 328 T38 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 329 T38 C4 oashd.DocBuilder.execute Time taken = 0:0:0.27
[junit4:junit4]   2> 330 T38 C4 UPDATE [collection1] webapp=null path=null params={indent=true&clean=true&commit=true&dataConfig=<dataConfig>+%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"People.ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=full-import&synchronous=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 34
[junit4:junit4]   2> 338 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=7 
[junit4:junit4]   2> 346 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=1 
[junit4:junit4]   2> 346 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 354 T38 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 354 T38 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 355 T38 C4 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 356 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 357 T38 C4 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 358 T38 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 358 T38 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 359 T38 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 362 T38 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 5
[junit4:junit4]   2> 362 T38 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 4
[junit4:junit4]   2> 363 T38 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 363 T38 C4 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 364 T38 C4 oashd.SolrWriter.deleteDoc Deleting document: 13
[junit4:junit4]   2> 364 T38 C4 oashd.SolrWriter.deleteDoc Deleting document: 15
[junit4:junit4]   2> 365 T38 C4 oashd.SolrWriter.deleteDoc Deleting document: 4
[junit4:junit4]   2> 365 T38 C4 oashd.SolrWriter.deleteDoc Deleting document: 7
[junit4:junit4]   2> 370 T38 C4 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 370 T38 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 371 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 389 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.frq, _0.tim, _0.fdx, _0.si, _0.tip, _0.fdt, segments_3]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_4,generation=4,filenames=[_0.fnm, _1.frq, _0_1.del, _1.fnm, _1.fdx, _1.fdt, _1.si, _0.tim, _0.frq, _0.fdx, _0.si, _1.tip, _0.tip, _1.tim, _0.fdt, segments_4]
[junit4:junit4]   2> 390 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 4
[junit4:junit4]   2> 394 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@2b2f3 main
[junit4:junit4]   2> 394 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 395 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 396 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2b2f3 main{StandardDirectoryReader(segments_4:8 _0(4.1):C20/9 _1(4.1):C5)}
[junit4:junit4]   2> 396 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 397 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 397 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 397 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 398 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2b2f3 main{StandardDirectoryReader(segments_4:8 _0(4.1):C20/9 _1(4.1):C5)}
[junit4:junit4]   2> 398 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 399 T38 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 400 T38 C4 oashd.DocBuilder.execute Time taken = 0:0:0.44
[junit4:junit4]   2> 400 T38 C4 UPDATE [collection1] webapp=null path=null params={indent=true&clean=false&commit=true&dataConfig=<dataConfig>+%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+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=[13, 15, 4, 7],add=[14, 1, 18, 5, 20],commit=} 0 49
[junit4:junit4]   2> 402 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=16 status=0 QTime=1 
[junit4:junit4]   2> 407 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 408 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 410 T38 C4 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> 413 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:7&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 415 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:13&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 418 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:15&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 421 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:1&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 425 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:18&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 433 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:5&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 437 T38 C4 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> 441 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:14&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 444 T38 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> 445 T38 oas.SolrTestCaseJ4.tearDown ###Ending testSingleEntity
[junit4:junit4]   2> 450 T38 oas.SolrTestCaseJ4.setUp ###Starting testChildEntities
[junit4:junit4]   2> 453 T38 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 453 T38 C4 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 457 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 458 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_4,generation=4,filenames=[_0.fnm, _1.frq, _0_1.del, _1.fnm, _1.fdx, _1.fdt, _1.si, _0.tim, _0.frq, _0.fdx, _0.si, _1.tip, _0.tip, _1.tim, _0.fdt, segments_4]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 459 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 5
[junit4:junit4]   2> 460 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@84bd76 main
[junit4:junit4]   2> 460 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 461 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 461 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@84bd76 main{StandardDirectoryReader(segments_5:9)}
[junit4:junit4]   2> 462 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 462 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 463 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 463 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 463 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@84bd76 main{StandardDirectoryReader(segments_5:9)}
[junit4:junit4]   2> 464 T38 C4 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 7
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> Sat Dec 01 04:18:55 MMT 2012:
[junit4:junit4]   2> Booting Derby version The Apache Software Foundation - Apache Derby - 10.9.1.0 - (1344872): instance a816c00e-013b-534b-314b-000001b15cf0 
[junit4:junit4]   2> on database directory memory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/derbyDB  with class loader sun.misc.Launcher$AppClassLoader@7c7894 
[junit4:junit4]   2> Loaded from file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar
[junit4:junit4]   2> java.vendor=Oracle Corporation
[junit4:junit4]   2> java.runtime.version=1.7.0_09-b05
[junit4:junit4]   2> user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1
[junit4:junit4]   2> derby.system.home=null
[junit4:junit4]   2> derby.stream.error.field=DerbyUtil.DEV_NULL
[junit4:junit4]   2> Database Class Loader started - derby.database.classpath=''
[junit4:junit4]   2> 728 T38 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 728 T38 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 729 T38 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 729 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 731 T38 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 732 T38 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;
[junit4:junit4]   2> 733 T38 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 739 T38 C4 oashd.JdbcDataSource$1.call Creating a connection for entity Countries with URL: jdbc:derby:memory:derbyDB;
[junit4:junit4]   2> 740 T38 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 853 T38 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 853 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 858 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_6,generation=6,filenames=[_2.si, _2.tip, _2.fdt, _2.frq, _2.fdx, segments_6, _2.tim, _2.fnm]
[junit4:junit4]   2> 858 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 6
[junit4:junit4]   2> 860 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@699775 main
[junit4:junit4]   2> 860 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 861 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 864 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@699775 main{StandardDirectoryReader(segments_6:12 _2(4.1):C20)}
[junit4:junit4]   2> 864 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 865 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 865 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 865 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 866 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@699775 main{StandardDirectoryReader(segments_6:12 _2(4.1):C20)}
[junit4:junit4]   2> 866 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 867 T38 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 868 T38 C4 oashd.DocBuilder.execute Time taken = 0:0:0.138
[junit4:junit4]   2> 869 T38 C4 UPDATE [collection1] webapp=null path=null params={indent=true&clean=true&commit=true&dataConfig=<dataConfig>+%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"People.ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"derby"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a<entity+name%3D"Countries"+pk%3D"CODE"+dataSource%3D"derby"+transformer%3D"AddAColumnTransformer"+newColumnName%3D"countryAdded_s"+newColumnValue%3D"country_added"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+CODE,+COUNTRY_NAME+FROM+COUNTRIES+WHERE+DELETED+!%3D+'Y'+AND+CODE%3D'${People.COUNTRY_CODE}'+"+>+%0a<field+column%3D"CODE"+name%3D"COUNTRY_CODE_s"+/>+%0a<field+column%3D"COUNTRY_NAME"+name%3D"COUNTRY_NAME_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=full-import&synchronous=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 145
[junit4:junit4]   2> 874 T38 C4 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> 898 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=NAME_mult_s:Jayden&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 921 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=COUNTRY_CODES_mult_s:NR&qt=standard&rows=20&version=2.2} hits=2 status=0 QTime=0 
[junit4:junit4]   2> 927 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=countryAdded_s:country_added&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=2 
[junit4:junit4]   2> 932 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 933 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=1 
[junit4:junit4]   2> 968 T38 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 969 T38 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 969 T38 C4 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 970 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 971 T38 C4 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 971 T38 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: Countries
[junit4:junit4]   2> 972 T38 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: Countries rows obtained : 0
[junit4:junit4]   2> 972 T38 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: Countries rows obtained : 0
[junit4:junit4]   2> 972 T38 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: Countries
[junit4:junit4]   2> 973 T38 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 973 T38 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;
[junit4:junit4]   2> 974 T38 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 1011 T38 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 1017 T38 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 4
[junit4:junit4]   2> 1018 T38 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 5
[junit4:junit4]   2> 1018 T38 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 1019 T38 C4 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 1020 T38 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 1020 T38 C4 oashd.SolrWriter.deleteDoc Deleting document: 19
[junit4:junit4]   2> 1021 T38 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 1021 T38 C4 oashd.SolrWriter.deleteDoc Deleting document: 1
[junit4:junit4]   2> 1021 T38 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 1022 T38 C4 oashd.SolrWriter.deleteDoc Deleting document: 2
[junit4:junit4]   2> 1022 T38 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 1023 T38 C4 oashd.SolrWriter.deleteDoc Deleting document: 17
[junit4:junit4]   2> 1023 T38 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4:junit4]   2> 1023 T38 C4 oashd.SolrWriter.deleteDoc Deleting document: 3
[junit4:junit4]   2> 1030 T38 C4 oashd.JdbcDataSource$1.call Creating a connection for entity Countries with URL: jdbc:derby:memory:derbyDB;
[junit4:junit4]   2> 1032 T38 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 1059 T38 C4 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 1059 T38 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1060 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1064 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_6,generation=6,filenames=[_2.si, _2.tip, _2.fdt, _2.frq, _2.fdx, segments_6, _2.tim, _2.fnm]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_7,generation=7,filenames=[_2.si, _3.frq, _3.tim, _2.frq, _2.fdt, _3.fdt, _3.fnm, _2.fdx, _2.fnm, _2.tim, _3.fdx, _2.tip, segments_7, _3.si, _3.tip, _2_1.del]
[junit4:junit4]   2> 1064 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 7
[junit4:junit4]   2> 1066 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@4a6e45 main
[junit4:junit4]   2> 1066 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1067 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1071 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4a6e45 main{StandardDirectoryReader(segments_7:15 _2(4.1):C20/8 _3(4.1):C4)}
[junit4:junit4]   2> 1072 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1072 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1073 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1073 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1073 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4a6e45 main{StandardDirectoryReader(segments_7:15 _2(4.1):C20/8 _3(4.1):C4)}
[junit4:junit4]   2> 1074 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1075 T38 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1075 T38 C4 oashd.DocBuilder.execute Time taken = 0:0:0.105
[junit4:junit4]   2> 1076 T38 C4 UPDATE [collection1] webapp=null path=null params={indent=true&clean=false&commit=true&dataConfig=<dataConfig>+%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"People.ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"derby"+transformer%3D"AddAColumnTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a<entity+name%3D"Countries"+pk%3D"Countries.CODE"+dataSource%3D"derby"+transformer%3D"AddAColumnTransformer"+newColumnName%3D"countryAdded_s"+newColumnValue%3D"country_added"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+CODE,+COUNTRY_NAME+FROM+COUNTRIES+WHERE+DELETED+!%3D+'Y'+AND+CODE%3D'${People.COUNTRY_CODE}'+"+>+%0a<field+column%3D"CODE"+name%3D"COUNTRY_CODE_s"+/>+%0a<field+column%3D"COUNTRY_NAME"+name%3D"COUNTRY_NAME_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=delta-import&synchronous=true} {delete=[19, 1, 2, 17, 3],add=[1012, 13, 10, 14],commit=} 0 110
[junit4:junit4]   2> 1079 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=16 status=0 QTime=1 
[junit4:junit4]   2> 1089 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=NAME_mult_s:Jayden&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1095 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=COUNTRY_CODES_mult_s:NR&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1099 T38 C4 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> 1101 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:17&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1103 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:1&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1106 T38 C4 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> 1108 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:19&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1110 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:3&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1113 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:10&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 1117 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:13&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1121 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:14&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> Sat Dec 01 04:18:56 MMT 2012:
[junit4:junit4]   2> Shutting down instance a816c00e-013b-534b-314b-000001b15cf0 on database directory memory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/derbyDB with class loader sun.misc.Launcher$AppClassLoader@7c7894 
[junit4:junit4]   2> 1633 T38 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> 1634 T38 oas.SolrTestCaseJ4.tearDown ###Ending testChildEntities
[junit4:junit4]   2> 1642 T38 oas.SolrTestCaseJ4.setUp ###Starting testWithComplexTransformer
[junit4:junit4]   2> 1648 T38 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1649 T38 C4 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4:junit4]   2> 1656 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1657 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_7,generation=7,filenames=[_2.si, _3.frq, _3.tim, _2.frq, _2.fdt, _3.fdt, _3.fnm, _2.fdx, _2.fnm, _2.tim, _3.fdx, _2.tip, segments_7, _3.si, _3.tip, _2_1.del]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 1658 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 8
[junit4:junit4]   2> 1659 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@5e32a1 main
[junit4:junit4]   2> 1660 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1661 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1661 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5e32a1 main{StandardDirectoryReader(segments_8:16)}
[junit4:junit4]   2> 1662 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1663 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1664 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1664 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1664 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5e32a1 main{StandardDirectoryReader(segments_8:16)}
[junit4:junit4]   2> 1665 T38 C4 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> Sat Dec 01 04:18:56 MMT 2012:
[junit4:junit4]   2> Booting Derby version The Apache Software Foundation - Apache Derby - 10.9.1.0 - (1344872): instance 266b0119-013b-534b-314b-000001b15cf0 
[junit4:junit4]   2> on database directory memory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/derbyDB  with class loader sun.misc.Launcher$AppClassLoader@7c7894 
[junit4:junit4]   2> Loaded from file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar
[junit4:junit4]   2> java.vendor=Oracle Corporation
[junit4:junit4]   2> java.runtime.version=1.7.0_09-b05
[junit4:junit4]   2> user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1
[junit4:junit4]   2> derby.system.home=null
[junit4:junit4]   2> derby.stream.error.field=DerbyUtil.DEV_NULL
[junit4:junit4]   2> Database Class Loader started - derby.database.classpath=''
[junit4:junit4]   2> 1863 T38 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1863 T38 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1864 T38 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 1865 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1865 T38 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1866 T38 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;
[junit4:junit4]   2> 1867 T38 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1904 T38 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1904 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1915 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_9,generation=9,filenames=[_4.fdx, segments_9, _4.frq, _4.tim, _4.fnm, _4.si, _4.fdt, _4.tip]
[junit4:junit4]   2> 1916 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 9
[junit4:junit4]   2> 1917 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@125be07 main
[junit4:junit4]   2> 1918 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 1918 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1930 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@125be07 main{StandardDirectoryReader(segments_9:19 _4(4.1):C60)}
[junit4:junit4]   2> 1931 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1932 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1932 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1933 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1933 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@125be07 main{StandardDirectoryReader(segments_9:19 _4(4.1):C60)}
[junit4:junit4]   2> 1934 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1935 T38 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1935 T38 C4 oashd.DocBuilder.execute Time taken = 0:0:0.70
[junit4:junit4]   2> 1936 T38 C4 UPDATE [collection1] webapp=null path=null params={indent=true&clean=true&commit=true&dataConfig=<dataConfig>+%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"derby"+transformer%3D"TripleThreatTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.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 78
[junit4:junit4]   2> 1946 T38 C4 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=60} hits=60 status=0 QTime=1 
[junit4:junit4]   2> 1960 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:TripleThreat-1-*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=1 
[junit4:junit4]   2> 1968 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:TripleThreat-2-*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=1 
[junit4:junit4]   2> 1992 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=%2Bid:TripleThreat-1-3+%2BNAME_mult_s:Michael+%2BNAME_mult_s:leahciM++%2BCOUNTRY_CODES_mult_s:NR+%2BCOUNTRY_CODES_mult_s:RN&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 1995 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=0 
[junit4:junit4]   2> 2000 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=1 
[junit4:junit4]   2> 2000 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 2019 T38 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 2019 T38 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 2020 T38 C4 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 2020 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 2021 T38 C4 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 2022 T38 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 2022 T38 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;
[junit4:junit4]   2> 2023 T38 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 2053 T38 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 21
[junit4:junit4]   2> 2054 T38 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
[junit4:junit4]   2> 2055 T38 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 2209 T38 C4 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 2209 T38 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 2210 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 2221 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_9,generation=9,filenames=[_4.fdx, segments_9, _4.frq, _4.tim, _4.fnm, _4.si, _4.fdt, _4.tip]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_a,generation=10,filenames=[_5.si, _5.tip, _5.fdt, _5.tim, _5.fnm, segments_a, _5.fdx, _5.frq]
[junit4:junit4]   2> 2222 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 10
[junit4:junit4]   2> 2224 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@14af49b main
[junit4:junit4]   2> 2225 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 2226 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2236 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@14af49b main{StandardDirectoryReader(segments_a:23 _5(4.1):C63)}
[junit4:junit4]   2> 2236 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 2237 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 2238 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 2238 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 2238 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14af49b main{StandardDirectoryReader(segments_a:23 _5(4.1):C63)}
[junit4:junit4]   2> 2239 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 2240 T38 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 2241 T38 C4 oashd.DocBuilder.execute Time taken = 0:0:0.221
[junit4:junit4]   2> 2241 T38 C4 UPDATE [collection1] webapp=null path=null params={indent=true&clean=false&commit=true&dataConfig=<dataConfig>+%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"derby"+transformer%3D"TripleThreatTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=delta-import&synchronous=true} {add=[1001, TripleThreat-1-1001, TripleThreat-2-1001, 17, TripleThreat-1-17, TripleThreat-2-17, 16, TripleThreat-1-16, TripleThreat-2-16, 19, ... (63 adds)],commit=} 0 224
[junit4:junit4]   2> 2249 T38 C4 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=63} hits=63 status=0 QTime=1 
[junit4:junit4]   2> 2263 T38 C4 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=0 
[junit4:junit4]   2> 2268 T38 C4 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=0 
[junit4:junit4]   2> 2277 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=%2Bid:TripleThreat-1-3+%2BNAME_mult_s:Michael+%2BNAME_mult_s:leahciM++%2BCOUNTRY_CODES_mult_s:NR+%2BCOUNTRY_CODES_mult_s:RN&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 2280 T38 C4 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=0 
[junit4:junit4]   2> 2285 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 2286 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> Sat Dec 01 04:18:57 MMT 2012:
[junit4:junit4]   2> Shutting down instance 266b0119-013b-534b-314b-000001b15cf0 on database directory memory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/derbyDB with class loader sun.misc.Launcher$AppClassLoader@7c7894 
[junit4:junit4]   2> 2792 T38 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> 2793 T38 oas.SolrTestCaseJ4.tearDown ###Ending testWithComplexTransformer
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSqlEntityProcessorDelta -Dtests.method=testWithComplexTransformer -Dtests.seed=FA2A49314043F780 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_EG -Dtests.timezone=Asia/Rangoon -Dtests.file.encoding=UTF-8
[junit4:junit4] FAILURE 1.20s J1 | TestSqlEntityProcessorDelta.testWithComplexTransformer <<<
[junit4:junit4]    > Throwable #1: junit.framework.AssertionFailedError: Expecting 6 database calls, but DIH reported 23
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([FA2A49314043F780:902038BA2BB5F93D]: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.AbstractSqlEntityProcessorTestCase.complexTransform(AbstractSqlEntityProcessorTestCase.java:111)
[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:57)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:601)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 2838 T38 oas.SolrTestCaseJ4.setUp ###Starting testWithSimpleTransformer
[junit4:junit4]   2> 2845 T38 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 2846 T38 C4 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 2850 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 2851 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_a,generation=10,filenames=[_5.si, _5.tip, _5.fdt, _5.tim, _5.fnm, segments_a, _5.fdx, _5.frq]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_b,generation=11,filenames=[segments_b]
[junit4:junit4]   2> 2851 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 11
[junit4:junit4]   2> 2852 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@c243e main
[junit4:junit4]   2> 2852 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 2853 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2854 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@c243e main{StandardDirectoryReader(segments_b:24)}
[junit4:junit4]   2> 2854 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 2854 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 2855 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 2855 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 2855 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c243e main{StandardDirectoryReader(segments_b:24)}
[junit4:junit4]   2> 2856 T38 C4 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 6
[junit4:junit4]   2> 2869 T38 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 2870 T38 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 2870 T38 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 2870 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 2871 T38 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 2872 T38 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 2873 T38 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 2883 T38 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 2883 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 2888 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_b,generation=11,filenames=[segments_b]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_c,generation=12,filenames=[segments_c, _6.tip, _6.frq, _6.tim, _6.fdx, _6.si, _6.fnm, _6.fdt]
[junit4:junit4]   2> 2889 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 12
[junit4:junit4]   2> 2891 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@1cfc780 main
[junit4:junit4]   2> 2891 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 2892 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2897 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1cfc780 main{StandardDirectoryReader(segments_c:27 _6(4.1):C20)}
[junit4:junit4]   2> 2898 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 2899 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 2899 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 2900 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 2900 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1cfc780 main{StandardDirectoryReader(segments_c:27 _6(4.1):C20)}
[junit4:junit4]   2> 2901 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 2902 T38 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 2902 T38 C4 oashd.DocBuilder.execute Time taken = 0:0:0.31
[junit4:junit4]   2> 2903 T38 C4 UPDATE [collection1] webapp=null path=null params={indent=true&clean=true&commit=true&dataConfig=<dataConfig>+%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"People.ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=full-import&synchronous=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 36
[junit4:junit4]   2> 2905 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=1 
[junit4:junit4]   2> 2912 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 2913 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 2916 T38 C4 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 2916 T38 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 2917 T38 C4 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 2917 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 2918 T38 C4 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 2919 T38 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 2919 T38 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 2920 T38 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 2922 T38 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 3
[junit4:junit4]   2> 2923 T38 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
[junit4:junit4]   2> 2923 T38 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 2926 T38 C4 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 2926 T38 C4 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 2927 T38 C4 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 2930 T38 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_c,generation=12,filenames=[segments_c, _6.tip, _6.frq, _6.tim, _6.fdx, _6.si, _6.fnm, _6.fdt]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8045ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@19382eb),segFN=segments_d,generation=13,filenames=[segments_d, _6.frq, _6.fdx, _7.si, _7.fdx, _6_1.del, _7.fdt, _7.fnm, _6.tip, _6.tim, _7.tim, _7.frq, _6.fnm, _6.si, _6.fdt, _7.tip]
[junit4:junit4]   2> 2931 T38 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 13
[junit4:junit4]   2> 2933 T38 C4 oass.SolrIndexSearcher.<init> Opening Searcher@1268f84 main
[junit4:junit4]   2> 2933 T38 C4 oass.SolrIndexSearcher.getIndexDir WARNING WARNING: Directory impl does not support setting indexDir: org.apache.lucene.store.MockDirectoryWrapper
[junit4:junit4]   2> 2934 T38 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2942 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1268f84 main{StandardDirectoryReader(segments_d:30 _6(4.1):C20/1 _7(4.1):C3)}
[junit4:junit4]   2> 2943 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 2943 T40 C4 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 2944 T40 C4 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 2944 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 2944 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1268f84 main{StandardDirectoryReader(segments_d:30 _6(4.1):C20/1 _7(4.1):C3)}
[junit4:junit4]   2> 2945 T38 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 2946 T38 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 2946 T38 C4 oashd.DocBuilder.execute Time taken = 0:0:0.28
[junit4:junit4]   2> 2946 T38 C4 UPDATE [collection1] webapp=null path=null params={indent=true&clean=false&commit=true&dataConfig=<dataConfig>+%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=delta-import&synchronous=true} {add=[19, 1018, 1003],commit=} 0 32
[junit4:junit4]   2> 2948 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=22 status=0 QTime=0 
[junit4:junit4]   2> 2952 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 2953 T38 C4 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 2954 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:1018&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 2956 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:1003&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 2958 T38 C4 REQ [collection1] webapp=null path=null params={start=0&q=id:19&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 2961 T38 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> 2962 T38 oas.SolrTestCaseJ4.tearDown ###Ending testWithSimpleTransformer
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> Sat Dec 01 04:18:57 MMT 2012: Shutting down Derby engine
[junit4:junit4]   2> ----------------------------------------------------------------
[junit4:junit4]   2> 2969 T38 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 2969 T38 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=33065800
[junit4:junit4]   2> 2969 T38 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@161dd83
[junit4:junit4]   2> 2969 T38 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=195,cumulative_deletesById=9,cumulative_deletesByQuery=8,cumulative_errors=0}
[junit4:junit4]   2> 2970 T38 oasc.SolrCore.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 2970 T38 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 2970 T38 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 2971 T38 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> NOTE: test params are: codec=Appending, sim=DefaultSimilarity, locale=ar_EG, timezone=Asia/Rangoon
[junit4:junit4]   2> NOTE: Linux 3.2.0-34-generic i386/Oracle Corporation 1.7.0_09 (32-bit)/cpus=8,threads=1,free=26949136,total=64880640
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestLineEntityProcessor, TestXPathRecordReader, TestEphemeralCache, TestErrorHandling, TestVariableResolverEndToEnd, TestSqlEntityProcessor, TestRegexTransformer, TestSqlEntityProcessorDelta]
[junit4:junit4] Completed on J1 in 3.01s, 4 tests, 1 failure <<< FAILURES!

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

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



Mime
View raw message