You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/08/11 11:34:35 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4796 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4796/
4 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta: 1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta:
1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:503)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([4995CC397B1EB902]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:503)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([4995CC397B1EB902]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestSimplePropertiesWriter
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSimplePropertiesWriter: 1) Thread[id=168, name=Timer-0, state=WAITING, group=TGRP-TestSimplePropertiesWriter] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSimplePropertiesWriter:
1) Thread[id=168, name=Timer-0, state=WAITING, group=TGRP-TestSimplePropertiesWriter]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:503)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([4995CC397B1EB902]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestSimplePropertiesWriter
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=168, name=Timer-0, state=WAITING, group=TGRP-TestSimplePropertiesWriter] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=168, name=Timer-0, state=WAITING, group=TGRP-TestSimplePropertiesWriter]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:503)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([4995CC397B1EB902]:0)
Build Log:
[...truncated 15053 lines...]
[junit4] Suite: org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001
[junit4] 2> 21861 T37 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 24248 T37 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 24249 T37 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/core-home-001/collection1/'
[junit4] 2> 24360 T37 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 24440 T37 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4] 2> 24442 T37 oass.IndexSchema.readSchema Reading Solr Schema from dataimport-schema.xml
[junit4] 2> 24462 T37 oass.IndexSchema.readSchema [null] Schema name=dih_test
[junit4] 2> 24519 T37 oass.IndexSchema.readSchema default search field in schema is desc
[junit4] 2> 24521 T37 oass.IndexSchema.readSchema query parser default operator is OR
[junit4] 2> 24522 T37 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 24524 T37 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 24525 T37 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/core-home-001
[junit4] 2> 24525 T37 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/core-home-001/'
[junit4] 2> 24592 T37 oasc.CoreContainer.<init> New CoreContainer 848423457
[junit4] 2> 24592 T37 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/core-home-001/]
[junit4] 2> 24594 T37 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 24595 T37 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 24595 T37 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 24595 T37 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 24596 T37 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 24596 T37 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 24597 T37 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 24597 T37 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 24598 T37 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 24717 T37 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=30000&connTimeout=30000&retry=false
[junit4] 2> 24720 T37 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 24721 T37 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 24721 T37 oasc.CoreContainer.load Host Name:
[junit4] 2> 24727 T39 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/core-home-001/collection1/'
[junit4] 2> 24883 T39 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 24956 T39 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4] 2> 24959 T39 oass.IndexSchema.readSchema Reading Solr Schema from dataimport-schema.xml
[junit4] 2> 24989 T39 oass.IndexSchema.readSchema [collection1] Schema name=dih_test
[junit4] 2> 25071 T39 oass.IndexSchema.readSchema default search field in schema is desc
[junit4] 2> 25073 T39 oass.IndexSchema.readSchema query parser default operator is OR
[junit4] 2> 25075 T39 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 25077 T39 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/core-home-001/collection1/
[junit4] 2> 25078 T39 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 25079 T39 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/core-home-001/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/
[junit4] 2> 25079 T39 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 25080 T39 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] 2> 25081 T39 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 25082 T39 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001
[junit4] 2> 25083 T39 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index/
[junit4] 2> 25083 T39 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index' doesn't exist. Creating new index...
[junit4] 2> 25084 T39 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index
[junit4] 2> 25088 T39 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> 25089 T39 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 25091 T39 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "" (default)
[junit4] 2> 25092 T39 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "" (default)
[junit4] 2> 25093 T39 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 25094 T39 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 25095 T39 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 25095 T39 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 25096 T39 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 25097 T39 oasc.RequestHandlers.initHandlersFromConfig created /dataimport: org.apache.solr.handler.dataimport.DataImportHandler
[junit4] 2> 25097 T39 oasc.RequestHandlers.initHandlersFromConfig created /search: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 25098 T39 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 25099 T39 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 25119 T39 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 25122 T39 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 25125 T39 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 25128 T39 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 25131 T39 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 25135 T39 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 25135 T39 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 25138 T39 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> 25138 T39 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 25139 T39 oass.SolrIndexSearcher.<init> Opening Searcher@7eadb544[collection1] main
[junit4] 2> 25141 T39 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/core-home-001/collection1/conf
[junit4] 2> 25142 T39 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/core-home-001/collection1/conf}
[junit4] 2> 25142 T39 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/core-home-001/collection1/conf
[junit4] 2> 25144 T39 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 25145 T39 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using file:dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/core-home-001/collection1/conf
[junit4] 2> 25146 T39 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 25147 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7eadb544[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 25147 T39 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 25147 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 25149 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7eadb544[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 25151 T37 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 25169 T37 oas.SolrTestCaseJ4.setUp ###Starting testSingleEntity
[junit4] 2> ASYNC NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@6fb9bb73
[junit4] 2> 25665 T37 C2 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 25673 T37 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 495
[junit4] 2> 25703 T37 C2 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 25705 T37 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_2,generation=2}
[junit4] 2> 25706 T37 C2 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 25708 T37 C2 oass.SolrIndexSearcher.<init> Opening Searcher@3ea07b48[collection1] main
[junit4] 2> 25708 T37 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 25709 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3ea07b48[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 25710 T40 C2 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 25711 T40 C2 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 25712 T40 C2 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 25713 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 25713 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3ea07b48[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 25714 T37 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 11
[junit4] 2> ASYNC NEW_CORE C3 name=collection1 org.apache.solr.core.SolrCore@6fb9bb73
[junit4] 2> 30205 T37 C3 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 30206 T37 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 30206 T37 C3 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 30268 T37 C3 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 30270 T37 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 30283 T37 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 30285 T37 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4] 2> 30514 T37 C3 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 30514 T37 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 30550 T37 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_3,generation=3}
[junit4] 2> 30550 T37 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 30573 T37 C3 oass.SolrIndexSearcher.<init> Opening Searcher@2727256[collection1] main
[junit4] 2> 30573 T37 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 30574 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2727256[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C20))}
[junit4] 2> 30575 T40 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 30576 T40 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 30578 T40 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 30578 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 30579 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2727256[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C20))}
[junit4] 2> 30580 T37 C3 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 30581 T37 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 30582 T37 C3 oashd.DocBuilder.execute Time taken = 0:0:0.312
[junit4] 2> 30582 T37 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.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&indent=true&commit=true&synchronous=true&clean=true&command=full-import} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 389
[junit4] 2> 30705 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=*:*&version=2.2&start=0&qt=standard} hits=20 status=0 QTime=3
[junit4] 2> 30724 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 30725 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 30726 T37 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 30824 T37 C3 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 30825 T37 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 30825 T37 C3 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 30826 T37 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 30828 T37 C3 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 30829 T37 C3 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 30829 T37 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 30831 T37 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4] 2> 31016 T37 C3 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 7
[junit4] 2> 31016 T37 C3 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 6
[junit4] 2> 31017 T37 C3 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 31017 T37 C3 oashd.DocBuilder.deleteAll Deleting stale documents
[junit4] 2> 31018 T37 C3 oashd.SolrWriter.deleteDoc Deleting document: 15
[junit4] 2> 31019 T37 C3 oashd.SolrWriter.deleteDoc Deleting document: 12
[junit4] 2> 31019 T37 C3 oashd.SolrWriter.deleteDoc Deleting document: 11
[junit4] 2> 31020 T37 C3 oashd.SolrWriter.deleteDoc Deleting document: 8
[junit4] 2> 31020 T37 C3 oashd.SolrWriter.deleteDoc Deleting document: 5
[junit4] 2> 31021 T37 C3 oashd.SolrWriter.deleteDoc Deleting document: 16
[junit4] 2> 31077 T37 C3 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 31077 T37 C3 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 31078 T37 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 31161 T37 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_4,generation=4}
[junit4] 2> 31162 T37 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 31172 T37 C3 oass.SolrIndexSearcher.<init> Opening Searcher@7fd00a54[collection1] main
[junit4] 2> 31173 T37 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 31175 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7fd00a54[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C20/12:delGen=1) Uninverting(_1(5.0):C7))}
[junit4] 2> 31176 T40 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 31177 T40 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 31178 T40 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 31179 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 31179 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7fd00a54[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C20/12:delGen=1) Uninverting(_1(5.0):C7))}
[junit4] 2> 31180 T37 C3 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 31181 T37 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 31182 T37 C3 oashd.DocBuilder.execute Time taken = 0:0:0.354
[junit4] 2> 31182 T37 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"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.People.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.People.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.People.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&indent=true&commit=true&synchronous=true&clean=false&command=delta-import} {delete=[15, 12, 11, 8, 5, 16],add=[20, 2, 17, 1, 14, 10, 1011],commit=} 0 370
[junit4] 2> 31188 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=*:*&version=2.2&start=0&qt=standard} hits=15 status=0 QTime=2
[junit4] 2> 31200 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 31201 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 31203 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:1011&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 31206 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:12&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=0
[junit4] 2> 31210 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:15&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=1
[junit4] 2> 31213 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:8&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=1
[junit4] 2> 31216 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:11&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=1
[junit4] 2> 31219 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:5&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=1
[junit4] 2> 31222 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:16&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=1
[junit4] 2> 31225 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:20&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=0
[junit4] 2> 31230 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:17&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 31235 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:1&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 31240 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:2&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 31244 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:14&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=0
[junit4] 2> 31249 T37 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:10&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 31869 T37 oas.SolrTestCaseJ4.tearDown ###Ending testSingleEntity
[junit4] 2> 31892 T37 oas.SolrTestCaseJ4.setUp ###Starting testWithSimpleTransformer
[junit4] 2> 31895 T37 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 31896 T37 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4] 2> 31904 T37 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 31906 T37 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_5,generation=5}
[junit4] 2> 31907 T37 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 31908 T37 C3 oass.SolrIndexSearcher.<init> Opening Searcher@718caed9[collection1] main
[junit4] 2> 31909 T37 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 31910 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@718caed9[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 31910 T40 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 31911 T40 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 31912 T40 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 31912 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 31913 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@718caed9[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 31914 T37 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4] 2> ASYNC NEW_CORE C4 name=collection1 org.apache.solr.core.SolrCore@6fb9bb73
[junit4] 2> 32579 T37 C4 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 32580 T37 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 32580 T37 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 32582 T37 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 32584 T37 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 32586 T37 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 32589 T37 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 2
[junit4] 2> 32735 T37 C4 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 32736 T37 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 32747 T37 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_5,generation=5}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_6,generation=6}
[junit4] 2> 32748 T37 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4] 2> 32751 T37 C4 oass.SolrIndexSearcher.<init> Opening Searcher@3248127b[collection1] main
[junit4] 2> 32752 T37 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 32758 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3248127b[collection1] main{UninvertingDirectoryReader(Uninverting(_2(5.0):C20))}
[junit4] 2> 32759 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 32760 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 32761 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 32762 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 32763 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3248127b[collection1] main{UninvertingDirectoryReader(Uninverting(_2(5.0):C20))}
[junit4] 2> 32764 T37 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 32765 T37 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 32766 T37 C4 oashd.DocBuilder.execute Time taken = 0:0:0.182
[junit4] 2> 32766 T37 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.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&indent=true&commit=true&synchronous=true&clean=true&command=full-import} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 208
[junit4] 2> 32786 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=AddAColumn_s:Added&version=2.2&start=0&qt=standard} hits=20 status=0 QTime=4
[junit4] 2> 32803 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 32804 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 32806 T37 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 32854 T37 C4 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 32855 T37 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 32855 T37 C4 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 32857 T37 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 32859 T37 C4 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 32860 T37 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 32861 T37 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 32864 T37 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4] 2> 32911 T37 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 5
[junit4] 2> 32912 T37 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 2
[junit4] 2> 32912 T37 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 32913 T37 C4 oashd.DocBuilder.deleteAll Deleting stale documents
[junit4] 2> 32914 T37 C4 oashd.SolrWriter.deleteDoc Deleting document: 17
[junit4] 2> 32915 T37 C4 oashd.SolrWriter.deleteDoc Deleting document: 11
[junit4] 2> 32972 T37 C4 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 32973 T37 C4 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 32974 T37 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 32985 T37 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_6,generation=6}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_7,generation=7}
[junit4] 2> 32986 T37 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 7
[junit4] 2> 32989 T37 C4 oass.SolrIndexSearcher.<init> Opening Searcher@403750f6[collection1] main
[junit4] 2> 32990 T37 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 32999 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@403750f6[collection1] main{UninvertingDirectoryReader(Uninverting(_2(5.0):C20/6:delGen=1) Uninverting(_3(5.0):C5))}
[junit4] 2> 33000 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 33001 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 33002 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 33003 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 33003 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@403750f6[collection1] main{UninvertingDirectoryReader(Uninverting(_2(5.0):C20/6:delGen=1) Uninverting(_3(5.0):C5))}
[junit4] 2> 33005 T37 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 33006 T37 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 33007 T37 C4 oashd.DocBuilder.execute Time taken = 0:0:0.149
[junit4] 2> 33007 T37 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"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.People.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.People.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.People.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&indent=true&commit=true&synchronous=true&clean=false&command=delta-import} {delete=[17, 11],add=[8, 9, 15, 13, 1001],commit=} 0 159
[junit4] 2> 33018 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=AddAColumn_s:Added&version=2.2&start=0&qt=standard} hits=19 status=0 QTime=5
[junit4] 2> 33033 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 33035 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 33037 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:1001&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 33042 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:17&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=1
[junit4] 2> 33046 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:11&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=0
[junit4] 2> 33050 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:15&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=0
[junit4] 2> 33058 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:13&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 33065 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:8&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 33073 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:9&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=2
[junit4] 2> 33591 T37 oas.SolrTestCaseJ4.tearDown ###Ending testWithSimpleTransformer
[junit4] 2> 33615 T37 oas.SolrTestCaseJ4.setUp ###Starting testChildEntities
[junit4] 2> 33618 T37 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 33620 T37 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4] 2> 33629 T37 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 33631 T37 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_7,generation=7}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_8,generation=8}
[junit4] 2> 33631 T37 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 8
[junit4] 2> 33633 T37 C4 oass.SolrIndexSearcher.<init> Opening Searcher@1094d8ba[collection1] main
[junit4] 2> 33633 T37 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 33635 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1094d8ba[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 33636 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 33637 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 33638 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 33639 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 33639 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1094d8ba[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 33641 T37 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 12
[junit4] 2> 34438 T37 C4 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 34438 T37 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 34439 T37 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 34440 T37 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 34441 T37 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 34442 T37 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 34443 T37 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 34453 T37 C4 oashd.JdbcDataSource$1.call Creating a connection for entity Sports with URL: jdbc:hsqldb:mem:.
[junit4] 2> 34454 T37 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 34476 T37 C4 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 34476 T37 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 34483 T37 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_8,generation=8}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_9,generation=9}
[junit4] 2> 34484 T37 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 9
[junit4] 2> 34486 T37 C4 oass.SolrIndexSearcher.<init> Opening Searcher@6687c01[collection1] main
[junit4] 2> 34486 T37 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 34491 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@6687c01[collection1] main{UninvertingDirectoryReader(Uninverting(_4(5.0):C20))}
[junit4] 2> 34491 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 34492 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 34493 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 34493 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 34493 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6687c01[collection1] main{UninvertingDirectoryReader(Uninverting(_4(5.0):C20))}
[junit4] 2> 34494 T37 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 34495 T37 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 34495 T37 C4 oashd.DocBuilder.execute Time taken = 0:0:0.54
[junit4] 2> 34496 T37 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a<entity+name%3D"Sports"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+newColumnName%3D"sportsAdded_s"+newColumnValue%3D"sport_added"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+ID,+SPORT_NAME+FROM+PEOPLE_SPORTS+WHERE+DELETED+!%3D+'Y'+AND+PERSON_ID%3D${People.ID}+ORDER+BY+ID"+>+%0a<field+column%3D"SPORT_NAME"+name%3D"SPORT_NAME_mult_s"+/>+%0a<field+column%3D"id"+name%3D"SPORT_ID_mult_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&indent=true&commit=true&synchronous=true&clean=true&command=full-import} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 78
[junit4] 2> 34498 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=*:*&version=2.2&start=0&qt=standard} hits=20 status=0 QTime=0
[junit4] 2> 34514 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=SPORT_NAME_mult_s:Sailing&version=2.2&start=0&qt=standard} hits=2 status=0 QTime=1
[junit4] 2> 34520 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=NAME_mult_s:Michael&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 34527 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=sportsAdded_s:sport_added&version=2.2&start=0&qt=standard} hits=20 status=0 QTime=1
[junit4] 2> 34537 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 34537 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 34538 T37 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 34552 T37 C4 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 34552 T37 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 34553 T37 C4 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 34553 T37 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 34555 T37 C4 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 34555 T37 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: Sports
[junit4] 2> 34556 T37 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: Sports rows obtained : 0
[junit4] 2> 34556 T37 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: Sports rows obtained : 0
[junit4] 2> 34557 T37 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: Sports
[junit4] 2> 34557 T37 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 34558 T37 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 34558 T37 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 34569 T37 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 3
[junit4] 2> 34569 T37 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 6
[junit4] 2> 34570 T37 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 34570 T37 C4 oashd.DocBuilder.deleteAll Deleting stale documents
[junit4] 2> 34571 T37 C4 oashd.SolrWriter.deleteDoc Deleting document: 3
[junit4] 2> 34571 T37 C4 oashd.SolrWriter.deleteDoc Deleting document: 1
[junit4] 2> 34572 T37 C4 oashd.SolrWriter.deleteDoc Deleting document: 19
[junit4] 2> 34572 T37 C4 oashd.SolrWriter.deleteDoc Deleting document: 14
[junit4] 2> 34573 T37 C4 oashd.SolrWriter.deleteDoc Deleting document: 4
[junit4] 2> 34573 T37 C4 oashd.SolrWriter.deleteDoc Deleting document: 9
[junit4] 2> 34574 T37 C4 oashd.JdbcDataSource$1.call Creating a connection for entity Sports with URL: jdbc:hsqldb:mem:.
[junit4] 2> 34575 T37 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 34580 T37 C4 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 34580 T37 C4 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 34581 T37 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 34587 T37 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_9,generation=9}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_a,generation=10}
[junit4] 2> 34587 T37 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 10
[junit4] 2> 34589 T37 C4 oass.SolrIndexSearcher.<init> Opening Searcher@6e792315[collection1] main
[junit4] 2> 34590 T37 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 34598 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@6e792315[collection1] main{UninvertingDirectoryReader(Uninverting(_4(5.0):C20/8:delGen=1) Uninverting(_5(5.0):C3))}
[junit4] 2> 34598 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 34599 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 34600 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 34600 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 34600 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6e792315[collection1] main{UninvertingDirectoryReader(Uninverting(_4(5.0):C20/8:delGen=1) Uninverting(_5(5.0):C3))}
[junit4] 2> 34601 T37 C4 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 34602 T37 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 34603 T37 C4 oashd.DocBuilder.execute Time taken = 0:0:0.48
[junit4] 2> 34603 T37 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a<entity+name%3D"Sports"+dataSource%3D"hsqldb"+transformer%3D"AddAColumnTransformer"+newColumnName%3D"sportsAdded_s"+newColumnValue%3D"sport_added"+processor%3D"SqlEntityProcessor"+query%3D"SELECT+ID,+SPORT_NAME+FROM+PEOPLE_SPORTS+WHERE+DELETED+!%3D+'Y'+AND+PERSON_ID%3D${People.ID}+ORDER+BY+ID"+>+%0a<field+column%3D"SPORT_NAME"+name%3D"SPORT_NAME_mult_s"+/>+%0a<field+column%3D"id"+name%3D"SPORT_ID_mult_s"+/>+%0a</entity>+%0a</entity>+%0a</document>+%0a</dataConfig>+%0a&indent=true&commit=true&synchronous=true&clean=false&command=delta-import} {delete=[3, 1, 19, 14, 4, 9],add=[5, 16, 1018],commit=} 0 56
[junit4] 2> 34605 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=*:*&version=2.2&start=0&qt=standard} hits=15 status=0 QTime=1
[junit4] 2> 34615 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:1018&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=0
[junit4] 2> 34618 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:14&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=0
[junit4] 2> 34621 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:9&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=0
[junit4] 2> 34624 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:4&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=1
[junit4] 2> 34627 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:1&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=1
[junit4] 2> 34630 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:3&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=1
[junit4] 2> 34633 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:19&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=1
[junit4] 2> 34635 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:5&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=0
[junit4] 2> 34639 T37 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:16&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=0
[junit4] 2> 34657 T37 oas.SolrTestCaseJ4.tearDown ###Ending testChildEntities
[junit4] 2> 34671 T37 oas.SolrTestCaseJ4.setUp ###Starting testWithComplexTransformer
[junit4] 2> 34673 T37 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 34674 T37 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 34683 T37 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 34683 T37 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_a,generation=10}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_b,generation=11}
[junit4] 2> 34684 T37 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 11
[junit4] 2> 34685 T37 C4 oass.SolrIndexSearcher.<init> Opening Searcher@73deb204[collection1] main
[junit4] 2> 34685 T37 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 34686 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@73deb204[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 34687 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 34688 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 34688 T40 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 34689 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 34689 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@73deb204[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> ASYNC NEW_CORE C5 name=collection1 org.apache.solr.core.SolrCore@6fb9bb73
[junit4] 2> 34701 T37 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 19
[junit4] 2> 34766 T37 C5 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 34767 T37 C5 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 34767 T37 C5 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 34768 T37 C5 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 34769 T37 C5 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 34770 T37 C5 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 34771 T37 C5 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 34909 T37 C5 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 34910 T37 C5 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 34939 T37 C5 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_b,generation=11}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_c,generation=12}
[junit4] 2> 34940 T37 C5 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 12
[junit4] 2> 34942 T37 C5 oass.SolrIndexSearcher.<init> Opening Searcher@659f58c7[collection1] main
[junit4] 2> 34943 T37 C5 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 34951 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@659f58c7[collection1] main{UninvertingDirectoryReader(Uninverting(_6(5.0):C60))}
[junit4] 2> 34952 T40 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 34953 T40 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 34954 T40 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 34955 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 34955 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@659f58c7[collection1] main{UninvertingDirectoryReader(Uninverting(_6(5.0):C60))}
[junit4] 2> 34956 T37 C5 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 34957 T37 C5 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 34958 T37 C5 oashd.DocBuilder.execute Time taken = 0:0:0.188
[junit4] 2> 34958 T37 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.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&indent=true&commit=true&synchronous=true&clean=true&command=full-import} {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 210
[junit4] 2> 35339 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=60&q=*:*&sort=id+asc} hits=60 status=0 QTime=379
[junit4] 2> 35397 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:TripleThreat-1-*&version=2.2&start=0&qt=standard} hits=20 status=0 QTime=34
[junit4] 2> 35405 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:TripleThreat-2-*&version=2.2&start=0&qt=standard} hits=20 status=0 QTime=1
[junit4] 2> 35423 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=%2Bid:TripleThreat-1-3+%2BNAME_mult_s:Michael+%2BNAME_mult_s:leahciM++%2BCOUNTRY_CODES_mult_s:NR+%2BCOUNTRY_CODES_mult_s:RN&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=11
[junit4] 2> 35427 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=AddAColumn_s:Added&version=2.2&start=0&qt=standard} hits=20 status=0 QTime=1
[junit4] 2> 35433 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 35434 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 35435 T37 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 35449 T37 C5 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 35450 T37 C5 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 35450 T37 C5 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 35451 T37 C5 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 35452 T37 C5 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 35453 T37 C5 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 35453 T37 C5 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 35454 T37 C5 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 35458 T37 C5 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 2
[junit4] 2> 35458 T37 C5 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 1
[junit4] 2> 35458 T37 C5 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 35459 T37 C5 oashd.DocBuilder.deleteAll Deleting stale documents
[junit4] 2> 35459 T37 C5 oashd.SolrWriter.deleteDoc Deleting document: 18
[junit4] 2> 35464 T37 C5 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 35465 T37 C5 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 35465 T37 C5 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 35470 T37 C5 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_c,generation=12}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_d,generation=13}
[junit4] 2> 35471 T37 C5 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 13
[junit4] 2> 35473 T37 C5 oass.SolrIndexSearcher.<init> Opening Searcher@11a2d231[collection1] main
[junit4] 2> 35474 T37 C5 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 35487 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@11a2d231[collection1] main{UninvertingDirectoryReader(Uninverting(_6(5.0):C60/1:delGen=1) Uninverting(_7(5.0):C6))}
[junit4] 2> 35488 T40 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 35489 T40 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 35489 T40 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearcher&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 35490 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 35490 T40 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@11a2d231[collection1] main{UninvertingDirectoryReader(Uninverting(_6(5.0):C60/1:delGen=1) Uninverting(_7(5.0):C6))}
[junit4] 2> 35491 T37 C5 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 35492 T37 C5 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 35492 T37 C5 oashd.DocBuilder.execute Time taken = 0:0:0.40
[junit4] 2> 35493 T37 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.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&indent=true&commit=true&synchronous=true&clean=false&command=delta-import} {delete=[18],add=[1003, TripleThreat-1-1003, TripleThreat-2-1003, 1008, TripleThreat-1-1008, TripleThreat-2-1008],commit=} 0 56
[junit4] 2> 35497 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=63&q=*:*&sort=id+asc} hits=65 status=0 QTime=2
[junit4] 2> 35517 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:TripleThreat-1-*&version=2.2&start=0&qt=standard} hits=22 status=0 QTime=0
[junit4] 2> 35524 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:TripleThreat-2-*&version=2.2&start=0&qt=standard} hits=22 status=0 QTime=0
[junit4] 2> 35532 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=%2Bid:TripleThreat-1-3+%2BNAME_mult_s:Michael+%2BNAME_mult_s:leahciM++%2BCOUNTRY_CODES_mult_s:NR+%2BCOUNTRY_CODES_mult_s:RN&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 35535 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=AddAColumn_s:Added&version=2.2&start=0&qt=standard} hits=22 status=0 QTime=0
[junit4] 2> 35541 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 35542 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 35544 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:1003&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 35547 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:1008&version=2.2&start=0&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 35550 T37 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=20&q=id:18&version=2.2&start=0&qt=standard} hits=0 status=0 QTime=0
[junit4] 2> 35553 T37 oas.SolrTestCaseJ4.tearDown ###Ending testWithComplexTransformer
[junit4] 2> 35567 T37 oas.SolrTestCaseJ4.setUp ###Starting testDeltaImportWithoutInitialFullImport
[junit4] 2> 35570 T37 C5 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 35570 T37 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 35577 T37 C5 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 35578 T37 C5 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_d,generation=13}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@551afa79 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-4995CC397B1EB902-001/init-core-data-001/index),segFN=segments_e,generation=14}
[junit4] 2> 35578 T37 C5 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 14
[junit4] 2> 35579 T37 C5 oass.SolrIndexSearcher.<init> Opening Searcher@5901eae8[collection1] main
[junit4] 2> 35580 T37 C5 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 35581 T40 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5901eae8[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 35582 T40 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=solr&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 35582 T40 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={rows=10&q=rocks&event=newSearcher&start=0&distrib=false} hits=0 status=0 QTime=0
[junit4] 2> 35583 T40 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&event=newSearche
[...truncated too long message...]
rtiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 84347 T167 C17 oashd.DocBuilder.execute Time taken = 0:0:0.24
[junit4] 2> 84347 T167 C17 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={commit=true&command=full-import&indent=true&synchronous=true&dataConfig=<dataConfig>+%0a<propertyWriter+dateFormat%3D"yyyy-MM-dd+HH:mm:ss.SSSSSS"+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSimplePropertiesWriter-4995CC397B1EB902-001/tempDir-001"+filename%3D"the.properties"+/>%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;territory%3Den_US"+/>+%0a<document+name%3D"TestSimplePropertiesWriter">+%0a<entity+name%3D"SomeDates"+processor%3D"SqlEntityProcessor"+dataSource%3D"derby"+query%3D"select+1+as+id,+YEAR('${dih.last_index_time}')+as+AYEAR_S+from+sysibm.sysdummy1+"+>%0a<field+column%3D"AYEAR_S"+name%3D"ayear_s"+/>+%0a</entity>%0a</document>+%0a</dataConfig>+%0a&clean=true} {deleteByQuery=*:*,add=[1],commit=} 0 29
[junit4] 2> 84348 T167 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 84351 T167 C17 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=*:*&start=0&qt=standard&rows=20&version=2.2} hits=1 status=0 QTime=1
[junit4] 2> 84960 T167 oas.SolrTestCaseJ4.tearDown ###Ending testSimplePropertiesWriter
[junit4] 2> 85075 T167 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 85075 T167 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1658162942
[junit4] 2> 85076 T167 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@155767ad
[junit4] 2> 85076 T167 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=5,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=4,cumulative_deletesById=0,cumulative_deletesByQuery=5,cumulative_errors=0}
[junit4] 2> 85077 T167 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 85077 T167 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 85077 T167 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 85080 T167 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 85080 T167 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 85081 T167 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSimplePropertiesWriter-4995CC397B1EB902-001/init-core-data-001 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSimplePropertiesWriter-4995CC397B1EB902-001/init-core-data-001;done=false>>]
[junit4] 2> 85081 T167 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSimplePropertiesWriter-4995CC397B1EB902-001/init-core-data-001
[junit4] 2> 85082 T167 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSimplePropertiesWriter-4995CC397B1EB902-001/init-core-data-001/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSimplePropertiesWriter-4995CC397B1EB902-001/init-core-data-001/index;done=false>>]
[junit4] 2> 85082 T167 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSimplePropertiesWriter-4995CC397B1EB902-001/init-core-data-001/index
[junit4] 2> 8021 T166 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> 28104 T166 ccr.ThreadLeakControl.checkThreadLeaks SEVERE 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSimplePropertiesWriter:
[junit4] 2> 1) Thread[id=168, name=Timer-0, state=WAITING, group=TGRP-TestSimplePropertiesWriter]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:503)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> 28104 T166 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=168, name=Timer-0, state=WAITING, group=TGRP-TestSimplePropertiesWriter]
[junit4] 2> 31111 T166 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=168, name=Timer-0, state=WAITING, group=TGRP-TestSimplePropertiesWriter]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:503)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> NOTE: test params are: codec=Lucene42, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=zh_CN, timezone=W-SU
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=16,threads=2,free=24975096,total=109051904
[junit4] 2> NOTE: All tests run in this JVM: [TestDocBuilder, TestURLDataSource, TestContentStreamDataSource, TestContextImpl, TestRegexTransformer, TestNumberFormatTransformer, TestEntityProcessorBase, TestErrorHandling, TestSolrEntityProcessorEndToEnd, TestPlainTextEntityProcessor, TestDateFormatTransformer, TestJdbcDataSource, TestEphemeralCache, TestTemplateTransformer, TestSimplePropertiesWriter]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestSimplePropertiesWriter -Dtests.seed=4995CC397B1EB902 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=zh_CN -Dtests.timezone=W-SU -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J1 | TestSimplePropertiesWriter (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSimplePropertiesWriter:
[junit4] > 1) Thread[id=168, name=Timer-0, state=WAITING, group=TGRP-TestSimplePropertiesWriter]
[junit4] > at java.lang.Object.wait(Native Method)
[junit4] > at java.lang.Object.wait(Object.java:503)
[junit4] > at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] > at java.util.TimerThread.run(Timer.java:505)
[junit4] > at __randomizedtesting.SeedInfo.seed([4995CC397B1EB902]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=168, name=Timer-0, state=WAITING, group=TGRP-TestSimplePropertiesWriter]
[junit4] > at java.lang.Object.wait(Native Method)
[junit4] > at java.lang.Object.wait(Object.java:503)
[junit4] > at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] > at java.util.TimerThread.run(Timer.java:505)
[junit4] > at __randomizedtesting.SeedInfo.seed([4995CC397B1EB902]:0)
[junit4] Completed on J1 in 31.23s, 1 test, 2 errors <<< FAILURES!
[...truncated 20 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:474: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:454: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:209: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:440: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:496: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1307: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:922: There were test failures: 37 suites, 148 tests, 4 suite-level errors, 89 ignored
Total time: 111 minutes 53 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-Tests-trunk-Java7 #4793
Archived 3 artifacts
Archive block size is 32768
Received 0 blocks and 1167503 bytes
Compression is 0.0%
Took 0.31 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
Re: [JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4798 - Still Failing
Posted by Steve Rowe <sa...@gmail.com>.
I couldn't login to lucene.zones.apache.org directly - connections timed
out for some reason. But I was able to login by first logging into
people.apache.org and from there into lucene.zones.apache.org. Once logged
in, I could see that /home/jenkins/ did not exist - instead /home/hudson/
has its expected contents. So I symlinked /home/jenkins to /home/hudson,
and hopefully that'll allow things to work.
On Mon, Aug 11, 2014 at 8:54 PM, Steve Rowe <sa...@gmail.com> wrote:
> From the build log:
>
> /tmp/hudson6964778820318780872.sh: line 3: /home/jenkins/tools/java/latest1.7/bin/java: No such file or directory
>
> There was a tweet from Infrastructure saying they were going to restart a
> bunch of VMs - maybe they upgraded lucene.zones.apache.org but didn't put
> the JVMs back?
>
> I'll investigate.
>
> Steve
>
> On Mon, Aug 11, 2014 at 8:46 PM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
>> Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4798/
>>
>> No tests ran.
>>
>> Build Log:
>> [...truncated 193 lines...]
>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>> For additional commands, e-mail: dev-help@lucene.apache.org
>>
>
>
Re: [JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4798 - Still Failing
Posted by Steve Rowe <sa...@gmail.com>.
>From the build log:
/tmp/hudson6964778820318780872.sh: line 3:
/home/jenkins/tools/java/latest1.7/bin/java: No such file or directory
There was a tweet from Infrastructure saying they were going to restart a
bunch of VMs - maybe they upgraded lucene.zones.apache.org but didn't put
the JVMs back?
I'll investigate.
Steve
On Mon, Aug 11, 2014 at 8:46 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4798/
>
> No tests ran.
>
> Build Log:
> [...truncated 193 lines...]
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
>
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4798 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4798/
No tests ran.
Build Log:
[...truncated 193 lines...]
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4797 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4797/
4 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestNestedChildren
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestNestedChildren: 1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestNestedChildren] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestNestedChildren:
1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestNestedChildren]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:503)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([C4CEFF93C1F92F7]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestNestedChildren
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestNestedChildren] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestNestedChildren]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:503)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([C4CEFF93C1F92F7]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta: 1) Thread[id=19, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta:
1) Thread[id=19, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:503)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([C4CEFF93C1F92F7]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=19, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=19, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:503)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([C4CEFF93C1F92F7]:0)
Build Log:
[...truncated 15046 lines...]
[junit4] Suite: org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001
[junit4] 2> 5399 T18 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
[junit4] 2> 9352 T18 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 9513 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/core-home-001/collection1/'
[junit4] 2> 10386 T18 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 10730 T18 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4] 2> 10761 T18 oass.IndexSchema.readSchema Reading Solr Schema from dataimport-schema.xml
[junit4] 2> 10804 T18 oass.IndexSchema.readSchema [null] Schema name=dih_test
[junit4] 2> 11453 T18 oass.IndexSchema.readSchema default search field in schema is desc
[junit4] 2> 11456 T18 oass.IndexSchema.readSchema query parser default operator is OR
[junit4] 2> 11458 T18 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 11499 T18 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 11500 T18 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/core-home-001
[junit4] 2> 11502 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/core-home-001/'
[junit4] 2> 11847 T18 oasc.CoreContainer.<init> New CoreContainer 633961589
[junit4] 2> 11854 T18 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/core-home-001/]
[junit4] 2> 11982 T18 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 11983 T18 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 11983 T18 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 11984 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 11984 T18 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 11985 T18 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 11986 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 11986 T18 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 11987 T18 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 13054 T18 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=30000&connTimeout=30000&retry=false
[junit4] 2> 13087 T18 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 13095 T18 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 13108 T18 oasc.CoreContainer.load Host Name:
[junit4] 2> 13885 T20 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/core-home-001/collection1/'
[junit4] 2> 14041 T20 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 14120 T20 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4] 2> 14123 T20 oass.IndexSchema.readSchema Reading Solr Schema from dataimport-schema.xml
[junit4] 2> 14145 T20 oass.IndexSchema.readSchema [collection1] Schema name=dih_test
[junit4] 2> 14223 T20 oass.IndexSchema.readSchema default search field in schema is desc
[junit4] 2> 14225 T20 oass.IndexSchema.readSchema query parser default operator is OR
[junit4] 2> 14227 T20 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 14235 T20 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/core-home-001/collection1/
[junit4] 2> 14421 T20 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 14488 T20 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/core-home-001/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/
[junit4] 2> 14489 T20 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 14560 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] 2> 14561 T20 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 14687 T20 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001
[junit4] 2> 14688 T20 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index/
[junit4] 2> 14689 T20 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index' doesn't exist. Creating new index...
[junit4] 2> 14690 T20 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index
[junit4] 2> 14958 T20 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> 14965 T20 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 16609 T20 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "" (default)
[junit4] 2> 16779 T20 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "" (default)
[junit4] 2> 16813 T20 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 16813 T20 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 16814 T20 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 16814 T20 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 16865 T20 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 16886 T20 oasc.RequestHandlers.initHandlersFromConfig created /dataimport: org.apache.solr.handler.dataimport.DataImportHandler
[junit4] 2> 16886 T20 oasc.RequestHandlers.initHandlersFromConfig created /search: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 16915 T20 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 16915 T20 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 16947 T20 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 16979 T20 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 16981 T20 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 16984 T20 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 16986 T20 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 17099 T20 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 17100 T20 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 17110 T20 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> 17111 T20 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 17279 T20 oass.SolrIndexSearcher.<init> Opening Searcher@691618bc[collection1] main
[junit4] 2> 17353 T20 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/core-home-001/collection1/conf
[junit4] 2> 17354 T20 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/core-home-001/collection1/conf}
[junit4] 2> 17501 T20 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/core-home-001/collection1/conf
[junit4] 2> 17502 T20 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 17521 T20 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using file:dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/core-home-001/collection1/conf
[junit4] 2> 17522 T20 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 17734 T20 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 17742 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@691618bc[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 17743 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 17743 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@691618bc[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 17772 T18 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 17784 T18 oas.SolrTestCaseJ4.setUp ###Starting testDeltaImportWithoutInitialFullImport
[junit4] 2> ASYNC NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@6c581399
[junit4] 2> 18181 T18 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 18194 T18 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 393
[junit4] 2> 18295 T18 C0 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 18304 T18 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_2,generation=2}
[junit4] 2> 18305 T18 C0 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 18306 T18 C0 oass.SolrIndexSearcher.<init> Opening Searcher@33dc3f69[collection1] main
[junit4] 2> 18322 T18 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 18322 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@33dc3f69[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 18451 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=119
[junit4] 2> 18456 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 18516 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=60
[junit4] 2> 18516 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 18517 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@33dc3f69[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 18518 T18 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 224
[junit4] 2> 19505 T18 C0 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 19506 T18 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 19534 T18 C0 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 19691 T18 C0 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 19878 T18 C0 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 19889 T18 C0 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 19900 T18 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 19900 T18 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 19935 T18 C0 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 20
[junit4] 2> 19935 T18 C0 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
[junit4] 2> 19936 T18 C0 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 20492 T18 C0 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 20492 T18 C0 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 20493 T18 C0 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 21056 T18 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_3,generation=3}
[junit4] 2> 21056 T18 C0 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 21146 T18 C0 oass.SolrIndexSearcher.<init> Opening Searcher@64c71e34[collection1] main
[junit4] 2> 21147 T18 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 21213 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@64c71e34[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C20))}
[junit4] 2> 21215 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=1
[junit4] 2> 21216 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=1
[junit4] 2> 21217 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 21218 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 21218 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@64c71e34[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C20))}
[junit4] 2> 21220 T18 C0 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 21221 T18 C0 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 21222 T18 C0 oashd.DocBuilder.execute Time taken = 0:0:1.528
[junit4] 2> 21222 T18 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.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&synchronous=true&indent=true&commit=true&clean=false&command=delta-import} {add=[20, 16, 17, 18, 19, 5, 4, 7, 6, 1, ... (20 adds)],commit=} 0 1843
[junit4] 2> 21230 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=*:*&rows=20&qt=standard&start=0} hits=20 status=0 QTime=6
[junit4] 2> 21285 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 21286 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 21296 T18 oas.SolrTestCaseJ4.tearDown ###Ending testDeltaImportWithoutInitialFullImport
[junit4] 2> 21310 T18 oas.SolrTestCaseJ4.setUp ###Starting testWithSimpleTransformer
[junit4] 2> 21312 T18 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 21312 T18 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 21318 T18 C0 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 21319 T18 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_4,generation=4}
[junit4] 2> 21320 T18 C0 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 21321 T18 C0 oass.SolrIndexSearcher.<init> Opening Searcher@43b9e4b4[collection1] main
[junit4] 2> 21321 T18 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 21322 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@43b9e4b4[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 21323 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 21324 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 21325 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 21326 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 21326 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@43b9e4b4[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 21328 T18 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4] 2> 21372 T18 C0 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 21372 T18 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 21373 T18 C0 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 21374 T18 C0 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 21375 T18 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 21377 T18 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 21377 T18 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 21456 T18 C0 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 21457 T18 C0 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 21465 T18 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_5,generation=5}
[junit4] 2> 21465 T18 C0 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 21468 T18 C0 oass.SolrIndexSearcher.<init> Opening Searcher@d5e6341[collection1] main
[junit4] 2> 21468 T18 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 21470 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@d5e6341[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C20))}
[junit4] 2> 21471 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=1
[junit4] 2> 21472 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=1
[junit4] 2> 21473 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 21474 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 21474 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d5e6341[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C20))}
[junit4] 2> 21475 T18 C0 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 21476 T18 C0 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 21477 T18 C0 oashd.DocBuilder.execute Time taken = 0:0:0.102
[junit4] 2> 21477 T18 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.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&synchronous=true&indent=true&commit=true&clean=true&command=full-import} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 118
[junit4] 2> 21493 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=AddAColumn_s:Added&rows=20&qt=standard&start=0} hits=20 status=0 QTime=14
[junit4] 2> 21509 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 21510 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 21511 T18 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 21521 T18 C0 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 21522 T18 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 21522 T18 C0 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 21523 T18 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 21525 T18 C0 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 21525 T18 C0 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 21526 T18 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 21527 T18 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 21529 T18 C0 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 21531 T18 C0 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 3
[junit4] 2> 21531 T18 C0 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 5
[junit4] 2> 21532 T18 C0 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 21533 T18 C0 oashd.DocBuilder.deleteAll Deleting stale documents
[junit4] 2> 21533 T18 C0 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 21534 T18 C0 oashd.SolrWriter.deleteDoc Deleting document: 13
[junit4] 2> 21534 T18 C0 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 21535 T18 C0 oashd.SolrWriter.deleteDoc Deleting document: 12
[junit4] 2> 21536 T18 C0 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 21536 T18 C0 oashd.SolrWriter.deleteDoc Deleting document: 16
[junit4] 2> 21537 T18 C0 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 21537 T18 C0 oashd.SolrWriter.deleteDoc Deleting document: 6
[junit4] 2> 21538 T18 C0 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 21538 T18 C0 oashd.SolrWriter.deleteDoc Deleting document: 5
[junit4] 2> 21542 T18 C0 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 21543 T18 C0 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 21543 T18 C0 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 21605 T18 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_5,generation=5}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_6,generation=6}
[junit4] 2> 21606 T18 C0 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4] 2> 21617 T18 C0 oass.SolrIndexSearcher.<init> Opening Searcher@15bea4b[collection1] main
[junit4] 2> 21618 T18 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 21621 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@15bea4b[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C20/6:delGen=1) Uninverting(_2(5.0):C3))}
[junit4] 2> 21622 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=1
[junit4] 2> 21623 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=1
[junit4] 2> 21624 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 21625 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 21625 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15bea4b[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C20/6:delGen=1) Uninverting(_2(5.0):C3))}
[junit4] 2> 21627 T18 C0 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 21628 T18 C0 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 21628 T18 C0 oashd.DocBuilder.execute Time taken = 0:0:0.104
[junit4] 2> 21629 T18 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.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&synchronous=true&indent=true&commit=true&clean=false&command=delta-import} {delete=[13, 12, 16, 6, 5],add=[20, 1001, 1002],commit=} 0 112
[junit4] 2> 21631 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=AddAColumn_s:Added&rows=20&qt=standard&start=0} hits=17 status=0 QTime=1
[junit4] 2> 21642 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 21643 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 21645 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:1002&rows=20&qt=standard&start=0} hits=1 status=0 QTime=1
[junit4] 2> 21649 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:1001&rows=20&qt=standard&start=0} hits=1 status=0 QTime=1
[junit4] 2> 21653 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:12&rows=20&qt=standard&start=0} hits=0 status=0 QTime=1
[junit4] 2> 21656 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:13&rows=20&qt=standard&start=0} hits=0 status=0 QTime=1
[junit4] 2> 21659 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:16&rows=20&qt=standard&start=0} hits=0 status=0 QTime=0
[junit4] 2> 21663 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:6&rows=20&qt=standard&start=0} hits=0 status=0 QTime=1
[junit4] 2> 21666 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:5&rows=20&qt=standard&start=0} hits=0 status=0 QTime=1
[junit4] 2> 21669 T18 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:20&rows=20&qt=standard&start=0} hits=1 status=0 QTime=0
[junit4] 2> 21675 T18 oas.SolrTestCaseJ4.tearDown ###Ending testWithSimpleTransformer
[junit4] 2> 21688 T18 oas.SolrTestCaseJ4.setUp ###Starting testWithComplexTransformer
[junit4] 2> 21691 T18 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 21692 T18 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4] 2> 21697 T18 C0 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 21698 T18 C0 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_6,generation=6}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_7,generation=7}
[junit4] 2> 21699 T18 C0 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 7
[junit4] 2> 21700 T18 C0 oass.SolrIndexSearcher.<init> Opening Searcher@5843066b[collection1] main
[junit4] 2> 21700 T18 C0 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 21701 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5843066b[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 21702 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 21702 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 21703 T21 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 21704 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 21704 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5843066b[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 21705 T18 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 8
[junit4] 2> 21749 T18 C0 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 21749 T18 C0 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 21750 T18 C0 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 21751 T18 C0 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 21752 T18 C0 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 21753 T18 C0 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 21754 T18 C0 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> ASYNC NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@6c581399
[junit4] 2> 21870 T18 C1 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 21871 T18 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 21908 T18 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_7,generation=7}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_8,generation=8}
[junit4] 2> 21909 T18 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 8
[junit4] 2> 21911 T18 C1 oass.SolrIndexSearcher.<init> Opening Searcher@69c76500[collection1] main
[junit4] 2> 21912 T18 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 21915 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@69c76500[collection1] main{UninvertingDirectoryReader(Uninverting(_3(5.0):C60))}
[junit4] 2> 21916 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 21917 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 21918 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 21918 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 21918 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@69c76500[collection1] main{UninvertingDirectoryReader(Uninverting(_3(5.0):C60))}
[junit4] 2> 21919 T18 C1 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 21920 T18 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 21921 T18 C1 oashd.DocBuilder.execute Time taken = 0:0:0.169
[junit4] 2> 21921 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.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&synchronous=true&indent=true&commit=true&clean=true&command=full-import} {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 184
[junit4] 2> 22306 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=60} hits=60 status=0 QTime=382
[junit4] 2> 22391 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:TripleThreat-1-*&rows=20&qt=standard&start=0} hits=20 status=0 QTime=42
[junit4] 2> 22404 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:TripleThreat-2-*&rows=20&qt=standard&start=0} hits=20 status=0 QTime=3
[junit4] 2> 22427 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=%2Bid:TripleThreat-1-3+%2BNAME_mult_s:Michael+%2BNAME_mult_s:leahciM++%2BCOUNTRY_CODES_mult_s:NR+%2BCOUNTRY_CODES_mult_s:RN&rows=20&qt=standard&start=0} hits=1 status=0 QTime=13
[junit4] 2> 22430 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=AddAColumn_s:Added&rows=20&qt=standard&start=0} hits=20 status=0 QTime=0
[junit4] 2> 22440 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 22441 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 22442 T18 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 22459 T18 C1 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 22460 T18 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 22460 T18 C1 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 22461 T18 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 22463 T18 C1 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 22463 T18 C1 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 22464 T18 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 22465 T18 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 22468 T18 C1 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 22470 T18 C1 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 4
[junit4] 2> 22471 T18 C1 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 1
[junit4] 2> 22471 T18 C1 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 22472 T18 C1 oashd.DocBuilder.deleteAll Deleting stale documents
[junit4] 2> 22473 T18 C1 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 22473 T18 C1 oashd.SolrWriter.deleteDoc Deleting document: 18
[junit4] 2> 22483 T18 C1 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 22483 T18 C1 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 22484 T18 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 22493 T18 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_8,generation=8}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_9,generation=9}
[junit4] 2> 22493 T18 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 9
[junit4] 2> 22496 T18 C1 oass.SolrIndexSearcher.<init> Opening Searcher@4428e2f1[collection1] main
[junit4] 2> 22497 T18 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 22507 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4428e2f1[collection1] main{UninvertingDirectoryReader(Uninverting(_3(5.0):C60/7:delGen=1) Uninverting(_4(5.0):C12))}
[junit4] 2> 22508 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=1
[junit4] 2> 22508 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 22509 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 22510 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 22510 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4428e2f1[collection1] main{UninvertingDirectoryReader(Uninverting(_3(5.0):C60/7:delGen=1) Uninverting(_4(5.0):C12))}
[junit4] 2> 22511 T18 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 22513 T18 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 22514 T18 C1 oashd.DocBuilder.execute Time taken = 0:0:0.52
[junit4] 2> 22514 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%0a<document+name%3D"TestSqlEntityProcessor">+%0a<entity+name%3D"People"+pk%3D"People.ID"+processor%3D"SqlEntityProcessor"+dataSource%3D"hsqldb"+transformer%3D"TripleThreatTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+deletedPkQuery%3D"SELECT+ID+FROM+PEOPLE+WHERE+DELETED%3D'Y'+AND+last_modified+%26gt;%3D'${dih.People.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.People.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.People.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&synchronous=true&indent=true&commit=true&clean=false&command=delta-import} {delete=[18],add=[9, TripleThreat-1-9, TripleThreat-2-9, 1011, TripleThreat-1-1011, TripleThreat-2-1011, 10, TripleThreat-1-10, TripleThreat-2-10, 1016, ... (12 adds)],commit=} 0 69
[junit4] 2> 22520 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={sort=id+asc&q=*:*&rows=63} hits=65 status=0 QTime=2
[junit4] 2> 22567 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:TripleThreat-1-*&rows=20&qt=standard&start=0} hits=22 status=0 QTime=1
[junit4] 2> 22579 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:TripleThreat-2-*&rows=20&qt=standard&start=0} hits=22 status=0 QTime=1
[junit4] 2> 22592 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=%2Bid:TripleThreat-1-3+%2BNAME_mult_s:Michael+%2BNAME_mult_s:leahciM++%2BCOUNTRY_CODES_mult_s:NR+%2BCOUNTRY_CODES_mult_s:RN&rows=20&qt=standard&start=0} hits=1 status=0 QTime=1
[junit4] 2> 22596 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=AddAColumn_s:Added&rows=20&qt=standard&start=0} hits=22 status=0 QTime=0
[junit4] 2> 22607 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 22608 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 22610 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:1011&rows=20&qt=standard&start=0} hits=1 status=0 QTime=1
[junit4] 2> 22615 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:1016&rows=20&qt=standard&start=0} hits=1 status=0 QTime=1
[junit4] 2> 22619 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:18&rows=20&qt=standard&start=0} hits=0 status=0 QTime=1
[junit4] 2> 22624 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:10&rows=20&qt=standard&start=0} hits=1 status=0 QTime=1
[junit4] 2> 22630 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:9&rows=20&qt=standard&start=0} hits=1 status=0 QTime=1
[junit4] 2> 22637 T18 oas.SolrTestCaseJ4.tearDown ###Ending testWithComplexTransformer
[junit4] 2> 22656 T18 oas.SolrTestCaseJ4.setUp ###Starting testSingleEntity
[junit4] 2> 22659 T18 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 22661 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4] 2> 22670 T18 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 22671 T18 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_9,generation=9}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_a,generation=10}
[junit4] 2> 22672 T18 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 10
[junit4] 2> 22673 T18 C1 oass.SolrIndexSearcher.<init> Opening Searcher@46921b16[collection1] main
[junit4] 2> 22674 T18 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 22676 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@46921b16[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 22677 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=1
[junit4] 2> 22677 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 22678 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 22679 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 22679 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@46921b16[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 22681 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 12
[junit4] 2> 22749 T18 C1 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 22750 T18 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 22751 T18 C1 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 22752 T18 C1 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 22754 T18 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 22756 T18 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 22757 T18 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 22772 T18 C1 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 22772 T18 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 22782 T18 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_a,generation=10}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_b,generation=11}
[junit4] 2> 22783 T18 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 11
[junit4] 2> 22786 T18 C1 oass.SolrIndexSearcher.<init> Opening Searcher@791cc3b0[collection1] main
[junit4] 2> 22787 T18 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 22793 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@791cc3b0[collection1] main{UninvertingDirectoryReader(Uninverting(_5(5.0):C20))}
[junit4] 2> 22794 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 22795 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=1
[junit4] 2> 22796 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 22796 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 22797 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@791cc3b0[collection1] main{UninvertingDirectoryReader(Uninverting(_5(5.0):C20))}
[junit4] 2> 22798 T18 C1 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 22799 T18 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 22800 T18 C1 oashd.DocBuilder.execute Time taken = 0:0:0.46
[junit4] 2> 22800 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.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&synchronous=true&indent=true&commit=true&clean=true&command=full-import} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 70
[junit4] 2> 22804 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=*:*&rows=20&qt=standard&start=0} hits=20 status=0 QTime=1
[junit4] 2> 22817 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 22818 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 22819 T18 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 22828 T18 C1 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 22829 T18 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 22830 T18 C1 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 22831 T18 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 22834 T18 C1 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 22835 T18 C1 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 22835 T18 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 22836 T18 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 22841 T18 C1 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 1
[junit4] 2> 22842 T18 C1 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 8
[junit4] 2> 22843 T18 C1 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 22844 T18 C1 oashd.DocBuilder.deleteAll Deleting stale documents
[junit4] 2> 22844 T18 C1 oashd.SolrWriter.deleteDoc Deleting document: 12
[junit4] 2> 22845 T18 C1 oashd.SolrWriter.deleteDoc Deleting document: 14
[junit4] 2> 22846 T18 C1 oashd.SolrWriter.deleteDoc Deleting document: 9
[junit4] 2> 22846 T18 C1 oashd.SolrWriter.deleteDoc Deleting document: 11
[junit4] 2> 22847 T18 C1 oashd.SolrWriter.deleteDoc Deleting document: 4
[junit4] 2> 22848 T18 C1 oashd.SolrWriter.deleteDoc Deleting document: 7
[junit4] 2> 22849 T18 C1 oashd.SolrWriter.deleteDoc Deleting document: 17
[junit4] 2> 22849 T18 C1 oashd.SolrWriter.deleteDoc Deleting document: 2
[junit4] 2> 22853 T18 C1 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 22853 T18 C1 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 22854 T18 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 22862 T18 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_b,generation=11}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_c,generation=12}
[junit4] 2> 22863 T18 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 12
[junit4] 2> 22866 T18 C1 oass.SolrIndexSearcher.<init> Opening Searcher@6fb1a043[collection1] main
[junit4] 2> 22867 T18 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 22877 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@6fb1a043[collection1] main{UninvertingDirectoryReader(Uninverting(_5(5.0):C20/9:delGen=1) Uninverting(_6(5.0):C1))}
[junit4] 2> 22878 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 22879 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 22880 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 22881 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 22881 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6fb1a043[collection1] main{UninvertingDirectoryReader(Uninverting(_5(5.0):C20/9:delGen=1) Uninverting(_6(5.0):C1))}
[junit4] 2> 22882 T18 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 22884 T18 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 22884 T18 C1 oashd.DocBuilder.execute Time taken = 0:0:0.52
[junit4] 2> 22885 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.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&synchronous=true&indent=true&commit=true&clean=false&command=delta-import} {delete=[12, 14, 9, 11, 4, 7, 17, 2],add=[16],commit=} 0 62
[junit4] 2> 22888 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=*:*&rows=20&qt=standard&start=0} hits=12 status=0 QTime=1
[junit4] 2> 22897 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 22898 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 22900 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:17&rows=20&qt=standard&start=0} hits=0 status=0 QTime=1
[junit4] 2> 22905 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:2&rows=20&qt=standard&start=0} hits=0 status=0 QTime=1
[junit4] 2> 22909 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:4&rows=20&qt=standard&start=0} hits=0 status=0 QTime=1
[junit4] 2> 22913 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:7&rows=20&qt=standard&start=0} hits=0 status=0 QTime=0
[junit4] 2> 22917 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:9&rows=20&qt=standard&start=0} hits=0 status=0 QTime=0
[junit4] 2> 22922 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:11&rows=20&qt=standard&start=0} hits=0 status=0 QTime=1
[junit4] 2> 22926 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:12&rows=20&qt=standard&start=0} hits=0 status=0 QTime=1
[junit4] 2> 22930 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:14&rows=20&qt=standard&start=0} hits=0 status=0 QTime=1
[junit4] 2> 22934 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=id:16&rows=20&qt=standard&start=0} hits=1 status=0 QTime=0
[junit4] 2> 22942 T18 oas.SolrTestCaseJ4.tearDown ###Ending testSingleEntity
[junit4] 2> 22958 T18 oas.SolrTestCaseJ4.setUp ###Starting testChildEntities
[junit4] 2> 22962 T18 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 22963 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 22975 T18 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 22977 T18 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_c,generation=12}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_d,generation=13}
[junit4] 2> 22977 T18 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 13
[junit4] 2> 22979 T18 C1 oass.SolrIndexSearcher.<init> Opening Searcher@5801e99a[collection1] main
[junit4] 2> 22979 T18 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 22981 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5801e99a[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 22982 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 22983 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 22984 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 22985 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 22985 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5801e99a[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 22987 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 12
[junit4] 2> 23075 T18 C1 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 23076 T18 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 23076 T18 C1 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 23078 T18 C1 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 23080 T18 C1 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 23081 T18 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 23082 T18 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 23083 T18 C1 oashd.JdbcDataSource$1.call Creating a connection for entity Countries with URL: jdbc:hsqldb:mem:.
[junit4] 2> 23084 T18 C1 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 23114 T18 C1 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 23114 T18 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 23126 T18 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_d,generation=13}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@548bc658 lockFactory=NativeFSLockFactory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/init-core-data-001/index),segFN=segments_e,generation=14}
[junit4] 2> 23127 T18 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 14
[junit4] 2> 23131 T18 C1 oass.SolrIndexSearcher.<init> Opening Searcher@7f2fa47a[collection1] main
[junit4] 2> 23132 T18 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 23139 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7f2fa47a[collection1] main{UninvertingDirectoryReader(Uninverting(_7(5.0):C20))}
[junit4] 2> 23140 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=1
[junit4] 2> 23140 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&rows=10&event=newSearcher&start=0} hits=0 status=0 QTime=0
[junit4] 2> 23141 T21 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 23142 T21 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 23142 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7f2fa47a[collection1] main{UninvertingDirectoryReader(Uninverting(_7(5.0):C20))}
[junit4] 2> 23143 T18 C1 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 23144 T18 C1 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 23145 T18 C1 oashd.DocBuilder.execute Time taken = 0:0:0.65
[junit4] 2> 23146 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J1/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-C4CEFF93C1F92F7-001/tempDir-001"+filename%3D"the.properties"+/>%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;territory%3Den_US"+/>+%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.People.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.People.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.People.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"hsqldb"+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&synchronous=true&indent=true&commit=true&clean=true&command=full-import} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 98
[junit4] 2> 23149 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=*:*&rows=20&qt=standard&start=0} hits=20 status=0 QTime=1
[junit4] 2> 23168 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=AddAColumn_s:Added&rows=20&qt=standard&start=0} hits=20 status=0 QTime=1
[junit4] 2> 23184 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=NAME_mult_s:Jayden&rows=20&qt=standard&start=0} hits=1 status=0 QTime=1
[junit4] 2> 23193 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=COUNTRY_CODES_mult_s:NR&rows=20&qt=standard&start=0} hits=2 status=0 QTime=1
[junit4] 2> 23202 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&q=countryAdded_s:country_added&rows=20&qt=standard&start=0} hits=20 status=0 QTime=1
[junit4] 2> 23217 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 23218 T18 C1 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 23220 T18 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 23230 T18 C1 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 23230 T18 C1 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 23231 T18 C1 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 23232 T18 C1 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 23234 T18 C1 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 23235 T18 C1 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: Countries
[junit4] 2> 23236 T18 C1 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: Countries rows obtained : 0
[junit4] 2> 23236 T18 C1 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: Countries rows obtained : 0
[junit4] 2> 23237 T18 C1 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: Countries
[junit4] 2> 23238 T18 C1 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 23238 T18 C1 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 23239 T18 C1 oashd.JdbcDataSource$1.call Time taken for getConn
[...truncated too long message...]
987 T37 C2 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4] 2> 30987 T37 C2 oashd.DocBuilder.execute Time taken = 0:0:1.568
[junit4] 2> 30988 T37 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={indent=true&command=full-import&synchronous=true&clean=true&dataConfig=<dataConfig>+%0a<dataSource+name%3D"derby"+driver%3D"org.apache.derby.jdbc.EmbeddedDriver"+url%3D"jdbc:derby:memory:derbyDB;territory%3Den_US"+/>+%0a<document+name%3D"TestSimplePropertiesWriter">+%0a<entity+name%3D"FIRST"+processor%3D"SqlEntityProcessor"+dataSource%3D"derby"++query%3D"select+1+as+id,+'PORK'+as+FIRST_S+from+sysibm.sysdummy1+"+>%0a++<field+column%3D"FIRST_S"+name%3D"first_s"+/>+%0a++<entity+name%3D"SECOND"+processor%3D"SqlEntityProcessor"+dataSource%3D"derby"++++query%3D"select+1+as+id,+2+as+SECOND_ID,+'BEEF'+as+SECOND_S+from+sysibm.sysdummy1+WHERE+1%3D${FIRST.ID}"+>%0a+++<field+column%3D"SECOND_S"+name%3D"second_s"+/>+%0a+++<entity+name%3D"THIRD"+processor%3D"SqlEntityProcessor"+dataSource%3D"derby"+++++query%3D"select+1+as+id,+'CHICKEN'+as+THIRD_S+from+sysibm.sysdummy1+WHERE+2%3D${SECOND.SECOND_ID}"+>%0a++++<field+column%3D"THIRD_S"+name%3D"third_s"+/>+%0a+++</entity>%0a++</entity>%0a</entity>%0a</document>+%0a</dataConfig>+%0a&commit=true} {deleteByQuery=*:*,add=[1],commit=} 0 1644
[junit4] 2> 30990 T37 C2 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&start=0&q=*:*&rows=20&qt=standard} hits=1 status=0 QTime=1
[junit4] 2> 31018 T37 C2 oasc.SolrCore.execute [collection1] webapp=null path=null params={version=2.2&start=0&q=third_s:CHICKEN&rows=20&qt=standard} hits=1 status=0 QTime=21
[junit4] 2> 31633 T37 oas.SolrTestCaseJ4.tearDown ###Ending test
[junit4] 2> 31771 T37 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 31771 T37 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1467863629
[junit4] 2> 31772 T37 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@74a9cfbd
[junit4] 2> 31773 T37 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1,cumulative_deletesById=0,cumulative_deletesByQuery=2,cumulative_errors=0}
[junit4] 2> 31773 T37 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 31774 T37 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 31775 T37 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 31777 T37 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 31778 T37 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 31778 T37 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestNestedChildren-C4CEFF93C1F92F7-001/init-core-data-001 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestNestedChildren-C4CEFF93C1F92F7-001/init-core-data-001;done=false>>]
[junit4] 2> 31779 T37 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestNestedChildren-C4CEFF93C1F92F7-001/init-core-data-001
[junit4] 2> 31780 T37 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestNestedChildren-C4CEFF93C1F92F7-001/init-core-data-001/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestNestedChildren-C4CEFF93C1F92F7-001/init-core-data-001/index;done=false>>]
[junit4] 2> 31780 T37 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestNestedChildren-C4CEFF93C1F92F7-001/init-core-data-001/index
[junit4] 2> 9029 T36 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> 29112 T36 ccr.ThreadLeakControl.checkThreadLeaks SEVERE 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestNestedChildren:
[junit4] 2> 1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestNestedChildren]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:503)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> 29113 T36 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestNestedChildren]
[junit4] 2> 32119 T36 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestNestedChildren]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:503)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> NOTE: test params are: codec=Lucene49: {timestamp=PostingsFormat(name=Memory doPackFST= true), third_s=FSTOrd41, id=FSTOrd41, second_s=PostingsFormat(name=Lucene41VarGapFixedInterval), first_s=PostingsFormat(name=Memory doPackFST= true)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=sv_SE, timezone=America/Atka
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=16,threads=2,free=102502160,total=157286400
[junit4] 2> NOTE: All tests run in this JVM: [TestZKPropertiesWriter, TestNestedChildren]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestNestedChildren -Dtests.seed=C4CEFF93C1F92F7 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sv_SE -Dtests.timezone=America/Atka -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J0 | TestNestedChildren (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestNestedChildren:
[junit4] > 1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestNestedChildren]
[junit4] > at java.lang.Object.wait(Native Method)
[junit4] > at java.lang.Object.wait(Object.java:503)
[junit4] > at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] > at java.util.TimerThread.run(Timer.java:505)
[junit4] > at __randomizedtesting.SeedInfo.seed([C4CEFF93C1F92F7]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=38, name=Timer-0, state=WAITING, group=TGRP-TestNestedChildren]
[junit4] > at java.lang.Object.wait(Native Method)
[junit4] > at java.lang.Object.wait(Object.java:503)
[junit4] > at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] > at java.util.TimerThread.run(Timer.java:505)
[junit4] > at __randomizedtesting.SeedInfo.seed([C4CEFF93C1F92F7]:0)
[junit4] Completed on J0 in 32.50s, 1 test, 2 errors <<< FAILURES!
[...truncated 11 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:474: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:454: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:209: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:440: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:496: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1307: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:922: There were test failures: 37 suites, 148 tests, 4 suite-level errors, 128 ignored
Total time: 110 minutes 18 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-Tests-trunk-Java7 #4793
Archived 3 artifacts
Archive block size is 32768
Received 0 blocks and 811928 bytes
Compression is 0.0%
Took 0.74 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure