lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@sd-datasolutions.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_09) - Build # 2266 - Failure!
Date Thu, 08 Nov 2012 00:31:04 GMT
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-trunk-Linux/2266/
Java: 32bit/jdk1.7.0_09 -server -XX:+UseParallelGC

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

Error Message:


Stack Trace:
junit.framework.AssertionFailedError
	at __randomizedtesting.SeedInfo.seed([F73A1BB4F48347F4:987E335E2E552BF9]:0)
	at junit.framework.Assert.fail(Assert.java:48)
	at junit.framework.Assert.assertTrue(Assert.java:20)
	at junit.framework.Assert.assertTrue(Assert.java:27)
	at org.apache.solr.handler.dataimport.AbstractDIHJdbcTestCase.simpleTransform(AbstractDIHJdbcTestCase.java:109)
	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testWithSimpleTransformer(TestSqlEntityProcessorDelta.java:51)
	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 11473 lines...]
[junit4:junit4] Suite: org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
[junit4:junit4]   2> 7 T20 oas.SolrTestCaseJ4.initCore ####initCore
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 8 T20 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/collection1/'
[junit4:junit4]   2> 62 T20 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 149 T20 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4:junit4]   2> 150 T20 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 162 T20 oass.IndexSchema.readSchema Schema name=dih_test
[junit4:junit4]   2> 248 T20 oass.IndexSchema.readSchema default search field in schema is desc
[junit4:junit4]   2> 250 T20 oass.IndexSchema.readSchema query parser default operator is OR
[junit4:junit4]   2> 252 T20 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 254 T20 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 254 T20 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr
[junit4:junit4]   2> 255 T20 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/'
[junit4:junit4]   2> 267 T20 oasc.CoreContainer.<init> New CoreContainer 20692876
[junit4:junit4]   2> 268 T20 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test-files/dih/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/
[junit4:junit4]   2> 268 T20 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 269 T20 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> 269 T20 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4:junit4]   2> 270 T20 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 271 T20 oasc.CachingDirectoryFactory.injectLockFactory WARNING No lockType configured for MockDirWrapper(org.apache.lucene.store.RAMDirectory@19c9a9b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6a4239) assuming 'simple'
[junit4:junit4]   2> 272 T20 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447 forceNew:false
[junit4:junit4]   2> 272 T20 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 273 T20 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index/
[junit4:junit4]   2> 274 T20 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 275 T20 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index forceNew:false
[junit4:junit4]   2> 280 T20 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 281 T20 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 282 T20 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 283 T20 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "" (default)
[junit4:junit4]   2> 286 T20 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 288 T20 oasc.RequestHandlers.initHandlersFromConfig created /dataimport: org.apache.solr.handler.dataimport.DataImportHandler
[junit4:junit4]   2> 289 T20 oasc.RequestHandlers.initHandlersFromConfig created /search: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 291 T20 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 296 T20 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 300 T20 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 302 T20 oass.SolrIndexSearcher.<init> Opening Searcher@1e7b49c main
[junit4:junit4]   2> 303 T20 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 303 T20 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 304 T20 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 304 T20 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 305 T20 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 306 T20 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 306 T20 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 307 T20 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 307 T20 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 308 T20 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 308 T20 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 309 T20 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 319 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1e7b49c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 319 T20 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 319 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 320 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e7b49c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 322 T20 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4:junit4]   2> 331 T20 oas.SolrTestCaseJ4.setUp ###Starting testWithSimpleTransformer
[junit4:junit4]   2> ASYNC  NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@189a628
[junit4:junit4]   2> 369 T20 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 369 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 371 T20 C1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 371 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 372 T20 C1 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 15
[junit4:junit4]   2> 382 T20 C1 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 383 T20 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 384 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 384 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 386 T20 C1 oass.SolrIndexSearcher.<init> Opening Searcher@1248d51 main
[junit4:junit4]   2> 388 T20 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 389 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1248d51 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 391 T21 C1 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> 391 T21 C1 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> 397 T21 C1 REQ [collection1] webapp=null path=null params={event=newSearcher&q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false} hits=0 status=0 QTime=5 
[junit4:junit4]   2> 398 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 398 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1248d51 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 399 T21 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 399 T20 C1 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 18
[junit4:junit4]   2> 576 T20 C1 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 576 T20 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 577 T20 C1 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 577 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 589 T20 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 593 T20 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 593 T20 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 676 T20 C1 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 676 T20 C1 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 808 T20 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_3,generation=3,filenames=[_0_NestedPulsing_0.doc, _0_Lucene41WithOrds_0.tib, _0_Lucene41WithOrds_0.doc, _0.fnm, _0_Memory_0.ram, _0_Lucene41WithOrds_0.tii, _0.fdx, _0.si, _0_NestedPulsing_0.tip, _0.fdt, segments_3, _0_NestedPulsing_0.tim]
[junit4:junit4]   2> 808 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0_NestedPulsing_0.doc, _0_Lucene41WithOrds_0.tib, _0_Lucene41WithOrds_0.doc, _0.fnm, _0_Memory_0.ram, _0_Lucene41WithOrds_0.tii, _0.fdx, _0.si, _0_NestedPulsing_0.tip, _0.fdt, segments_3, _0_NestedPulsing_0.tim]
[junit4:junit4]   2> 809 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 841 T20 C1 oass.SolrIndexSearcher.<init> Opening Searcher@156ff8a main
[junit4:junit4]   2> 842 T20 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 854 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@156ff8a main{StandardDirectoryReader(segments_3:5 _0(5.0):C20)}
[junit4:junit4]   2> 855 T21 C1 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> 856 T21 C1 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> 857 T21 C1 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> 857 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 857 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@156ff8a main{StandardDirectoryReader(segments_3:5 _0(5.0):C20)}
[junit4:junit4]   2> 858 T21 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 859 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 860 T20 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 860 T20 C1 oashd.DocBuilder.execute Time taken = 0:0:0.282
[junit4:junit4]   2> 861 T20 C1 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}'+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 289
[junit4:junit4]   2> 876 T20 C1 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=14 
[junit4:junit4]   2> 890 T20 C1 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 898 T20 C1 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 898 T20 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 899 T20 C1 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 899 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 900 T20 C1 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 901 T20 C1 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 901 T20 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 902 T20 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 908 T20 C1 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 15
[junit4:junit4]   2> 908 T20 C1 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 5
[junit4:junit4]   2> 909 T20 C1 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 909 T20 C1 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 910 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 19
[junit4:junit4]   2> 910 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 18
[junit4:junit4]   2> 911 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 7
[junit4:junit4]   2> 911 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 12
[junit4:junit4]   2> 912 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 17
[junit4:junit4]   2> 926 T20 C1 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 927 T20 C1 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 927 T20 C1 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 951 T20 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_3,generation=3,filenames=[_0_NestedPulsing_0.doc, _0_Lucene41WithOrds_0.tib, _0_Lucene41WithOrds_0.doc, _0.fnm, _0_Memory_0.ram, _0_Lucene41WithOrds_0.tii, _0.fdx, _0.si, _0_NestedPulsing_0.tip, _0.fdt, segments_3, _0_NestedPulsing_0.tim]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_4,generation=4,filenames=[_1_NestedPulsing_0.doc, _1_NestedPulsing_0.tip, _1.fdx, _1_Memory_0.ram, _1.fdt, _1.si, _1_Lucene41WithOrds_0.tii, _1_Lucene41WithOrds_0.doc, _1_Lucene41WithOrds_0.tib, _1_NestedPulsing_0.tim, _1.fnm, segments_4]
[junit4:junit4]   2> 951 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_1_NestedPulsing_0.doc, _1_NestedPulsing_0.tip, _1.fdx, _1_Memory_0.ram, _1.fdt, _1.si, _1_Lucene41WithOrds_0.tii, _1_Lucene41WithOrds_0.doc, _1_Lucene41WithOrds_0.tib, _1_NestedPulsing_0.tim, _1.fnm, segments_4]
[junit4:junit4]   2> 953 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 955 T20 C1 oass.SolrIndexSearcher.<init> Opening Searcher@1931c47 main
[junit4:junit4]   2> 956 T20 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 957 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1931c47 main{StandardDirectoryReader(segments_4:9 _1(5.0):C15)}
[junit4:junit4]   2> 957 T21 C1 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=solr&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 958 T21 C1 REQ [collection1] webapp=null path=null params={start=0&event=newSearcher&q=rocks&distrib=false&rows=10} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 959 T21 C1 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> 959 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 960 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1931c47 main{StandardDirectoryReader(segments_4:9 _1(5.0):C15)}
[junit4:junit4]   2> 961 T21 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 961 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 962 T20 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 963 T20 C1 oashd.DocBuilder.execute Time taken = 0:0:0.63
[junit4:junit4]   2> 963 T20 C1 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, 18, 7, 12, 17],add=[1, 6, 13, 2, 3, 4, 5, 16, 11, 10, ... (15 adds)],commit=} 0 69
[junit4:junit4]   2> 965 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=15 status=0 QTime=1 
[junit4:junit4]   2> 976 T20 C1 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 977 T20 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 978 T20 oas.SolrTestCaseJ4.tearDown ###Ending testWithSimpleTransformer
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSqlEntityProcessorDelta -Dtests.method=testWithSimpleTransformer -Dtests.seed=F73A1BB4F48347F4 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_AU -Dtests.timezone=Brazil/East -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE 0.72s J1 | TestSqlEntityProcessorDelta.testWithSimpleTransformer <<<
[junit4:junit4]    > Throwable #1: junit.framework.AssertionFailedError
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([F73A1BB4F48347F4:987E335E2E552BF9]:0)
[junit4:junit4]    > 	at junit.framework.Assert.fail(Assert.java:48)
[junit4:junit4]    > 	at junit.framework.Assert.assertTrue(Assert.java:20)
[junit4:junit4]    > 	at junit.framework.Assert.assertTrue(Assert.java:27)
[junit4:junit4]    > 	at org.apache.solr.handler.dataimport.AbstractDIHJdbcTestCase.simpleTransform(AbstractDIHJdbcTestCase.java:109)
[junit4:junit4]    > 	at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta.testWithSimpleTransformer(TestSqlEntityProcessorDelta.java:51)
[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> 1050 T20 oas.SolrTestCaseJ4.setUp ###Starting testSingleEntity
[junit4:junit4]   2> 1055 T20 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1056 T20 C1 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 1062 T20 C1 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1063 T20 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_4,generation=4,filenames=[_1_NestedPulsing_0.doc, _1_NestedPulsing_0.tip, _1.fdx, _1_Memory_0.ram, _1.fdt, _1.si, _1_Lucene41WithOrds_0.tii, _1_Lucene41WithOrds_0.doc, _1_Lucene41WithOrds_0.tib, _1_NestedPulsing_0.tim, _1.fnm, segments_4]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 1063 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 5[segments_5]
[junit4:junit4]   2> 1064 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 1065 T20 C1 oass.SolrIndexSearcher.<init> Opening Searcher@16168c4 main
[junit4:junit4]   2> 1066 T20 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1066 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@16168c4 main{StandardDirectoryReader(segments_5:10)}
[junit4:junit4]   2> 1067 T21 C1 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> 1068 T21 C1 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> 1069 T21 C1 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> 1069 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1069 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16168c4 main{StandardDirectoryReader(segments_5:10)}
[junit4:junit4]   2> 1070 T21 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 1071 T20 C1 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 9
[junit4:junit4]   2> 1082 T20 C1 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1083 T20 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1083 T20 C1 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 1084 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1085 T20 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1085 T20 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1086 T20 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1097 T20 C1 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1098 T20 C1 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1103 T20 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_6,generation=6,filenames=[_2.si, _2_Lucene41WithOrds_0.doc, _2_NestedPulsing_0.tim, _2_Lucene41WithOrds_0.tii, _2.fdt, _2_Lucene41WithOrds_0.tib, _2_Memory_0.ram, _2.fdx, segments_6, _2_NestedPulsing_0.tip, _2_NestedPulsing_0.doc, _2.fnm]
[junit4:junit4]   2> 1104 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 6[_2.si, _2_Lucene41WithOrds_0.doc, _2_NestedPulsing_0.tim, _2_Lucene41WithOrds_0.tii, _2.fdt, _2_Lucene41WithOrds_0.tib, _2_Memory_0.ram, _2.fdx, segments_6, _2_NestedPulsing_0.tip, _2_NestedPulsing_0.doc, _2.fnm]
[junit4:junit4]   2> 1104 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 1107 T20 C1 oass.SolrIndexSearcher.<init> Opening Searcher@86510a main
[junit4:junit4]   2> 1108 T20 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1108 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@86510a main{StandardDirectoryReader(segments_6:13 _2(5.0):C20)}
[junit4:junit4]   2> 1109 T21 C1 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> 1110 T21 C1 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> 1111 T21 C1 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> 1111 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1112 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@86510a main{StandardDirectoryReader(segments_6:13 _2(5.0):C20)}
[junit4:junit4]   2> 1112 T21 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 1113 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1114 T20 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1114 T20 C1 oashd.DocBuilder.execute Time taken = 0:0:0.30
[junit4:junit4]   2> 1114 T20 C1 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"+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 35
[junit4:junit4]   2> 1117 T20 C1 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> 1130 T20 C1 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1136 T20 C1 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1137 T20 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1138 T20 C1 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 1139 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1140 T20 C1 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 1140 T20 C1 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 1141 T20 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1142 T20 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1153 T20 C1 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 4
[junit4:junit4]   2> 1154 T20 C1 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 4
[junit4:junit4]   2> 1155 T20 C1 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 1155 T20 C1 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 1156 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 10
[junit4:junit4]   2> 1156 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 12
[junit4:junit4]   2> 1156 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 16
[junit4:junit4]   2> 1157 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 4
[junit4:junit4]   2> 1161 T20 C1 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 1161 T20 C1 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1162 T20 C1 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1167 T20 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_6,generation=6,filenames=[_2.si, _2_Lucene41WithOrds_0.doc, _2_NestedPulsing_0.tim, _2_Lucene41WithOrds_0.tii, _2.fdt, _2_Lucene41WithOrds_0.tib, _2_Memory_0.ram, _2.fdx, segments_6, _2_NestedPulsing_0.tip, _2_NestedPulsing_0.doc, _2.fnm]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_7,generation=7,filenames=[_2_NestedPulsing_0.tim, _2_Lucene41WithOrds_0.doc, _2.si, _2_Lucene41WithOrds_0.tii, _3_Lucene41WithOrds_0.doc, _3_NestedPulsing_0.tim, _2.fdt, _2_Lucene41WithOrds_0.tib, _3.fdt, _3.fnm, _2.fdx, _2.fnm, _3.fdx, _3_NestedPulsing_0.doc, segments_7, _3_Lucene41WithOrds_0.tib, _3_NestedPulsing_0.tip, _3.si, _2_Memory_0.ram, _3_Memory_0.ram, _2_1.del, _3_Lucene41WithOrds_0.tii, _2_NestedPulsing_0.tip, _2_NestedPulsing_0.doc]
[junit4:junit4]   2> 1168 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 7[_2_NestedPulsing_0.tim, _2_Lucene41WithOrds_0.doc, _2.si, _2_Lucene41WithOrds_0.tii, _3_Lucene41WithOrds_0.doc, _3_NestedPulsing_0.tim, _2.fdt, _2_Lucene41WithOrds_0.tib, _3.fdt, _3.fnm, _2.fdx, _2.fnm, _3.fdx, _3_NestedPulsing_0.doc, segments_7, _3_Lucene41WithOrds_0.tib, _3_NestedPulsing_0.tip, _3.si, _2_Memory_0.ram, _3_Memory_0.ram, _2_1.del, _3_Lucene41WithOrds_0.tii, _2_NestedPulsing_0.tip, _2_NestedPulsing_0.doc]
[junit4:junit4]   2> 1168 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 1174 T20 C1 oass.SolrIndexSearcher.<init> Opening Searcher@d4d3cf main
[junit4:junit4]   2> 1174 T20 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1175 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@d4d3cf main{StandardDirectoryReader(segments_7:16 _2(5.0):C20/6 _3(5.0):C4)}
[junit4:junit4]   2> 1176 T21 C1 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> 1177 T21 C1 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> 1178 T21 C1 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> 1178 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1179 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d4d3cf main{StandardDirectoryReader(segments_7:16 _2(5.0):C20/6 _3(5.0):C4)}
[junit4:junit4]   2> 1179 T21 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 1180 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1181 T20 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1181 T20 C1 oashd.DocBuilder.execute Time taken = 0:0:0.42
[junit4:junit4]   2> 1182 T20 C1 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=[10, 12, 16, 4],add=[1015, 17, 1017, 20],commit=} 0 49
[junit4:junit4]   2> 1184 T20 C1 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> 1192 T20 C1 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=1 
[junit4:junit4]   2> 1194 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:1017&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 1199 T20 C1 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> 1203 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:16&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1206 T20 C1 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> 1209 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:10&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1212 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:12&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1215 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:17&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1221 T20 C1 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> 1225 T20 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 1225 T20 oas.SolrTestCaseJ4.tearDown ###Ending testSingleEntity
[junit4:junit4]   2> 1232 T20 oas.SolrTestCaseJ4.setUp ###Starting testWithComplexTransformer
[junit4:junit4]   2> 1236 T20 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1237 T20 C1 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> 1244 T20 C1 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1245 T20 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_7,generation=7,filenames=[_2_NestedPulsing_0.tim, _2_Lucene41WithOrds_0.doc, _2.si, _2_Lucene41WithOrds_0.tii, _3_Lucene41WithOrds_0.doc, _3_NestedPulsing_0.tim, _2.fdt, _2_Lucene41WithOrds_0.tib, _3.fdt, _3.fnm, _2.fdx, _2.fnm, _3.fdx, _3_NestedPulsing_0.doc, segments_7, _3_Lucene41WithOrds_0.tib, _3_NestedPulsing_0.tip, _3.si, _2_Memory_0.ram, _3_Memory_0.ram, _2_1.del, _3_Lucene41WithOrds_0.tii, _2_NestedPulsing_0.tip, _2_NestedPulsing_0.doc]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 1245 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 8[segments_8]
[junit4:junit4]   2> 1246 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 1247 T20 C1 oass.SolrIndexSearcher.<init> Opening Searcher@177dfad main
[junit4:junit4]   2> 1247 T20 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1248 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@177dfad main{StandardDirectoryReader(segments_8:17)}
[junit4:junit4]   2> 1249 T21 C1 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> 1249 T21 C1 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> 1250 T21 C1 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> 1251 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1251 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@177dfad main{StandardDirectoryReader(segments_8:17)}
[junit4:junit4]   2> 1252 T21 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 1253 T20 C1 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4:junit4]   2> 1263 T20 C1 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1264 T20 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1264 T20 C1 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 1264 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1265 T20 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1266 T20 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1267 T20 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 1316 T20 C1 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1317 T20 C1 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1332 T20 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_8,generation=8,filenames=[segments_8]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_9,generation=9,filenames=[_4.fdx, segments_9, _4_NestedPulsing_0.doc, _4_Lucene41WithOrds_0.tii, _4_Memory_0.ram, _4_Lucene41WithOrds_0.doc, _4_NestedPulsing_0.tip, _4.fnm, _4_NestedPulsing_0.tim, _4.si, _4.fdt, _4_Lucene41WithOrds_0.tib]
[junit4:junit4]   2> 1333 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 9[_4.fdx, segments_9, _4_NestedPulsing_0.doc, _4_Lucene41WithOrds_0.tii, _4_Memory_0.ram, _4_Lucene41WithOrds_0.doc, _4_NestedPulsing_0.tip, _4.fnm, _4_NestedPulsing_0.tim, _4.si, _4.fdt, _4_Lucene41WithOrds_0.tib]
[junit4:junit4]   2> 1334 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 1338 T20 C1 oass.SolrIndexSearcher.<init> Opening Searcher@1904c66 main
[junit4:junit4]   2> 1338 T20 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1341 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1904c66 main{StandardDirectoryReader(segments_9:20 _4(5.0):C60)}
[junit4:junit4]   2> 1341 T21 C1 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> 1342 T21 C1 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> 1343 T21 C1 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> 1344 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1344 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1904c66 main{StandardDirectoryReader(segments_9:20 _4(5.0):C60)}
[junit4:junit4]   2> 1344 T21 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 1345 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1346 T20 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1347 T20 C1 oashd.DocBuilder.execute Time taken = 0:0:0.82
[junit4:junit4]   2> 1347 T20 C1 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 87
[junit4:junit4]   2> 1393 T20 C1 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=60} hits=60 status=0 QTime=45 
[junit4:junit4]   2> 1445 T20 C1 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=14 
[junit4:junit4]   2> 1456 T20 C1 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=2 
[junit4:junit4]   2> 1467 T20 C1 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> 1476 T20 C1 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1477 T20 C1 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1485 T20 C1 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1486 T20 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1487 T20 C1 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 1487 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1488 T20 C1 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 1489 T20 C1 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 1490 T20 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1491 T20 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 1495 T20 C1 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 6
[junit4:junit4]   2> 1496 T20 C1 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 5
[junit4:junit4]   2> 1496 T20 C1 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 1497 T20 C1 oashd.DocBuilder.deleteAll Deleting stale documents 
[junit4:junit4]   2> 1498 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 8
[junit4:junit4]   2> 1498 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 1
[junit4:junit4]   2> 1499 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 16
[junit4:junit4]   2> 1500 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 3
[junit4:junit4]   2> 1500 T20 C1 oashd.SolrWriter.deleteDoc Deleting document: 7
[junit4:junit4]   2> 1519 T20 C1 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 1519 T20 C1 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1520 T20 C1 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1533 T20 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_9,generation=9,filenames=[_4.fdx, segments_9, _4_NestedPulsing_0.doc, _4_Lucene41WithOrds_0.tii, _4_Memory_0.ram, _4_Lucene41WithOrds_0.doc, _4_NestedPulsing_0.tip, _4.fnm, _4_NestedPulsing_0.tim, _4.si, _4.fdt, _4_Lucene41WithOrds_0.tib]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_a,generation=10,filenames=[_5_NestedPulsing_0.tip, _5_Memory_0.ram, _5.fdt, _5_Lucene41WithOrds_0.tib, _5.fnm, _5_NestedPulsing_0.tim, segments_a, _4_NestedPulsing_0.doc, _5_Lucene41WithOrds_0.doc, _5_Lucene41WithOrds_0.tii, _4_Lucene41WithOrds_0.tii, _5_NestedPulsing_0.doc, _4.fnm, _4.fdt, _4.si, _4_Lucene41WithOrds_0.tib, _5.si, _4.fdx, _4_Memory_0.ram, _4_Lucene41WithOrds_0.doc, _5.fdx, _4_NestedPulsing_0.tip, _4_1.del, _4_NestedPulsing_0.tim]
[junit4:junit4]   2> 1535 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 10[_5_NestedPulsing_0.tip, _5_Memory_0.ram, _5.fdt, _5_Lucene41WithOrds_0.tib, _5.fnm, _5_NestedPulsing_0.tim, segments_a, _4_NestedPulsing_0.doc, _5_Lucene41WithOrds_0.doc, _5_Lucene41WithOrds_0.tii, _4_Lucene41WithOrds_0.tii, _5_NestedPulsing_0.doc, _4.fnm, _4.fdt, _4.si, _4_Lucene41WithOrds_0.tib, _5.si, _4.fdx, _4_Memory_0.ram, _4_Lucene41WithOrds_0.doc, _5.fdx, _4_NestedPulsing_0.tip, _4_1.del, _4_NestedPulsing_0.tim]
[junit4:junit4]   2> 1535 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 1540 T20 C1 oass.SolrIndexSearcher.<init> Opening Searcher@ac12e0 main
[junit4:junit4]   2> 1541 T20 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1549 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@ac12e0 main{StandardDirectoryReader(segments_a:23 _4(5.0):C60/20 _5(5.0):C18)}
[junit4:junit4]   2> 1550 T21 C1 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> 1551 T21 C1 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> 1552 T21 C1 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> 1552 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1553 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ac12e0 main{StandardDirectoryReader(segments_a:23 _4(5.0):C60/20 _5(5.0):C18)}
[junit4:junit4]   2> 1553 T21 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 1554 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1555 T20 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1556 T20 C1 oashd.DocBuilder.execute Time taken = 0:0:0.68
[junit4:junit4]   2> 1556 T20 C1 UPDATE [collection1] webapp=null path=null params={indent=true&clean=false&commit=true&dataConfig=<dataConfig>+%0a<dataSource+name%3D"hsqldb"+driver%3D"org.hsqldb.jdbcDriver"+url%3D"jdbc:hsqldb:mem:."+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+transformer%3D"TripleThreatTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+"+deltaImportQuery%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+where+ID%3D${dih.delta.ID}+"+deltaQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+last_modified+%26gt;%3D'${dih.last_index_time}'+UNION+DISTINCT+SELECT+ID+FROM+PEOPLE+WHERE+DELETED!%3D'Y'+AND+COUNTRY_CODE+IN+(SELECT+CODE+FROM+COUNTRIES+WHERE+last_modified+%26gt;%3D'${dih.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=delta-import&synchronous=true} {delete=[8, 1, 16, 3, 7],add=[17, TripleThreat-1-17, TripleThreat-2-17, 19, TripleThreat-1-19, TripleThreat-2-19, 18, TripleThreat-1-18, TripleThreat-2-18, 5, ... (18 adds)],commit=} 0 76
[junit4:junit4]   2> 1559 T20 C1 REQ [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=48} hits=58 status=0 QTime=1 
[junit4:junit4]   2> 1577 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:TripleThreat-1-*&qt=standard&rows=20&version=2.2} hits=21 status=0 QTime=1 
[junit4:junit4]   2> 1587 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:TripleThreat-2-*&qt=standard&rows=20&version=2.2} hits=21 status=0 QTime=1 
[junit4:junit4]   2> 1597 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=AddAColumn_s:Added&qt=standard&rows=20&version=2.2} hits=21 status=0 QTime=1 
[junit4:junit4]   2> 1605 T20 C1 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1606 T20 C1 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1607 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:1006&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1611 T20 C1 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> 1615 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:16&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 1619 T20 C1 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> 1622 T20 C1 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> 1626 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:8&qt=standard&rows=20&version=2.2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 1630 T20 C1 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> 1636 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:19&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 1641 T20 C1 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> 1647 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:5&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1653 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=id:6&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 1658 T20 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 1659 T20 oas.SolrTestCaseJ4.tearDown ###Ending testWithComplexTransformer
[junit4:junit4]   2> 1679 T20 oas.SolrTestCaseJ4.setUp ###Starting testChildEntities
[junit4:junit4]   2> 1685 T20 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1686 T20 C1 UPDATE [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4:junit4]   2> 1694 T20 C1 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1695 T20 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_a,generation=10,filenames=[_5_NestedPulsing_0.tip, _5_Memory_0.ram, _5.fdt, _5_Lucene41WithOrds_0.tib, _5.fnm, _5_NestedPulsing_0.tim, segments_a, _4_NestedPulsing_0.doc, _5_Lucene41WithOrds_0.doc, _5_Lucene41WithOrds_0.tii, _4_Lucene41WithOrds_0.tii, _5_NestedPulsing_0.doc, _4.fnm, _4.fdt, _4.si, _4_Lucene41WithOrds_0.tib, _5.si, _4.fdx, _4_Memory_0.ram, _4_Lucene41WithOrds_0.doc, _5.fdx, _4_NestedPulsing_0.tip, _4_1.del, _4_NestedPulsing_0.tim]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_b,generation=11,filenames=[segments_b]
[junit4:junit4]   2> 1696 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 11[segments_b]
[junit4:junit4]   2> 1697 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 1698 T20 C1 oass.SolrIndexSearcher.<init> Opening Searcher@106499d main
[junit4:junit4]   2> 1699 T20 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1700 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@106499d main{StandardDirectoryReader(segments_b:24)}
[junit4:junit4]   2> 1700 T21 C1 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> 1701 T21 C1 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> 1701 T21 C1 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> 1702 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1702 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@106499d main{StandardDirectoryReader(segments_b:24)}
[junit4:junit4]   2> 1703 T21 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 1703 T20 C1 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4:junit4]   2> 1716 T20 C1 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1717 T20 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1717 T20 C1 oashd.DataImporter.doFullImport Starting Full Import
[junit4:junit4]   2> 1718 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1719 T20 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 1721 T20 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1721 T20 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1723 T20 C1 oashd.JdbcDataSource$1.call Creating a connection for entity Sports with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1723 T20 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4:junit4]   2> 1755 T20 C1 oashd.DocBuilder.finish Import completed successfully
[junit4:junit4]   2> 1755 T20 C1 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 1769 T20 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_b,generation=11,filenames=[segments_b]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15bfd2d lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce4c9c),segFN=segments_c,generation=12,filenames=[_6_Memory_0.ram, segments_c, _6.fdx, _6_TestBloomFilteredLucene41Postings_0.tip, _6_TestBloomFilteredLucene41Postings_0.blm, _6_Lucene41WithOrds_0.tib, _6_TestBloomFilteredLucene41Postings_0.tim, _6_TestBloomFilteredLucene41Postings_0.doc, _6_Lucene41WithOrds_0.tii, _6_Lucene41WithOrds_0.doc, _6_NestedPulsing_0.doc, _6_NestedPulsing_0.tip, _6.si, _6.fnm, _6.fdt, _6_NestedPulsing_0.tim]
[junit4:junit4]   2> 1769 T20 C1 oasc.SolrDeletionPolicy.updateCommits newest commit = 12[_6_Memory_0.ram, segments_c, _6.fdx, _6_TestBloomFilteredLucene41Postings_0.tip, _6_TestBloomFilteredLucene41Postings_0.blm, _6_Lucene41WithOrds_0.tib, _6_TestBloomFilteredLucene41Postings_0.tim, _6_TestBloomFilteredLucene41Postings_0.doc, _6_Lucene41WithOrds_0.tii, _6_Lucene41WithOrds_0.doc, _6_NestedPulsing_0.doc, _6_NestedPulsing_0.tip, _6.si, _6.fnm, _6.fdt, _6_NestedPulsing_0.tim]
[junit4:junit4]   2> 1770 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447
[junit4:junit4]   2> 1782 T20 C1 oass.SolrIndexSearcher.<init> Opening Searcher@6581ce main
[junit4:junit4]   2> 1783 T20 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1788 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@6581ce main{StandardDirectoryReader(segments_c:27 _6(5.0):C20)}
[junit4:junit4]   2> 1789 T21 C1 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> 1789 T21 C1 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> 1790 T21 C1 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> 1791 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4:junit4]   2> 1791 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6581ce main{StandardDirectoryReader(segments_c:27 _6(5.0):C20)}
[junit4:junit4]   2> 1794 T21 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 1794 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1795 T20 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4:junit4]   2> 1796 T20 C1 oashd.DocBuilder.execute Time taken = 0:0:0.77
[junit4:junit4]   2> 1796 T20 C1 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}'+"+>+%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 85
[junit4:junit4]   2> 1799 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=0 
[junit4:junit4]   2> 1811 T20 C1 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=3 
[junit4:junit4]   2> 1821 T20 C1 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=4 
[junit4:junit4]   2> 1833 T20 C1 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1834 T20 C1 REQ [collection1] webapp=null path=null params={indent=true} status=0 QTime=0 
[junit4:junit4]   2> 1840 T20 C1 oashdc.ConfigParseUtil.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4:junit4]   2> 1841 T20 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4:junit4]   2> 1841 T20 C1 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4:junit4]   2> 1842 T20 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read dataimport.properties
[junit4:junit4]   2> 1843 T20 C1 oashd.DocBuilder.doDelta Starting delta collection.
[junit4:junit4]   2> 1843 T20 C1 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: Sports
[junit4:junit4]   2> 1844 T20 C1 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: Sports rows obtained : 0
[junit4:junit4]   2> 1845 T20 C1 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: Sports rows obtained : 0
[junit4:junit4]   2> 1845 T20 C1 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: Sports
[junit4:junit4]   2> 1846 T20 C1 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4:junit4]   2> 1847 T20 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4:junit4]   2> 1848 T20 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4:junit4]   2> 1851 T20 C1 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 0
[junit4:junit4]   2> 1851 T20 C1 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
[junit4:junit4]   2> 1852 T20 C1 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4:junit4]   2> 1853 T20 C1 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4:junit4]   2> 1853 T20 C1 oashd.DocBuilder.execute Time taken = 0:0:0.10
[junit4:junit4]   2> 1854 T20 C1 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}'+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a<entity+name%3D"Sports"+dataSource%3D"hsqldb"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+ID,+SPORT_NAME+FROM+PEOPLE_SPORTS+WHERE+DELETED+!%3D+'Y'+AND+PERSON_ID%3D'${People.ID}'+ORDER+BY+ID"+>+%0a<field+column%3D"SPORT_NAME"+name%3D"SPORT_NAME_mult_s"+/>+%0a<field+column%3D"id"+name%3D"SPORT_ID_mult_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&command=delta-import&synchronous=true} {} 0 17
[junit4:junit4]   2> 1856 T20 C1 REQ [collection1] webapp=null path=null params={start=0&q=*:*&qt=standard&rows=20&version=2.2} hits=20 status=0 QTime=1 
[junit4:junit4]   2> 1864 T20 C1 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> 1873 T20 oashd.AbstractDataImportHandlerTestCase.tearDown Looking for dataimport.properties at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/solr/collection1/conf/dataimport.properties
[junit4:junit4]   2> 1874 T20 oas.SolrTestCaseJ4.tearDown ###Ending testChildEntities
[junit4:junit4]   2> 1879 T20 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 1880 T20 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=20692876
[junit4:junit4]   2> 1880 T20 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@189a628
[junit4:junit4]   2> 1881 T20 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=11,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=157,cumulative_deletesById=14,cumulative_deletesByQuery=8,cumulative_errors=0}
[junit4:junit4]   2> 1881 T20 oasc.SolrCore.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 1882 T20 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 1882 T20 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 1883 T20 C1 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> 1884 T20 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 1935 T20 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-dataimporthandler/test/J1/./solrtest-TestSqlEntityProcessorDelta-1352334653447/index
[junit4:junit4]   2> NOTE: test params are: codec=Lucene41: {timestamp=PostingsFormat(name=NestedPulsing), id=PostingsFormat(name=Memory doPackFST= true), COUNTRY_CODES_mult_s=PostingsFormat(name=Lucene41WithOrds), SPORT_NAME_mult_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), AddAColumn_s=PostingsFormat(name=NestedPulsing), NAME_mult_s=PostingsFormat(name=Lucene41WithOrds)}, sim=DefaultSimilarity, locale=en_AU, timezone=Brazil/East
[junit4:junit4]   2> NOTE: Linux 3.2.0-32-generic i386/Oracle Corporation 1.7.0_09 (32-bit)/cpus=8,threads=1,free=68220432,total=132251648
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestNonWritablePersistFile, TestPlainTextEntityProcessor, TestFieldReader, TestSqlEntityProcessorDelta]
[junit4:junit4] Completed on J1 in 1.98s, 4 tests, 1 failure <<< FAILURES!

[...truncated 88 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:335: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:192: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:410: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/module-build.xml:61: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1163: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:827: There were test failures: 33 suites, 138 tests, 1 failure, 5 ignored

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



Mime
View raw message