You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/08/10 16:10:36 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 1761
- Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1761/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseParallelGC
2 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=48, 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=48, 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([AF00CD81A18CE2F6]: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=48, 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=48, 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([AF00CD81A18CE2F6]:0)
Build Log:
[...truncated 15317 lines...]
[junit4] Suite: org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001
[junit4] 2> 34887 T47 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 38130 T47 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 38132 T47 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/core-home-001/collection1/'
[junit4] 2> 38278 T47 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 38348 T47 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4] 2> 38354 T47 oass.IndexSchema.readSchema Reading Solr Schema from dataimport-schema.xml
[junit4] 2> 38381 T47 oass.IndexSchema.readSchema [null] Schema name=dih_test
[junit4] 2> 38471 T47 oass.IndexSchema.readSchema default search field in schema is desc
[junit4] 2> 38472 T47 oass.IndexSchema.readSchema query parser default operator is OR
[junit4] 2> 38474 T47 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 38476 T47 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 38477 T47 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/core-home-001
[junit4] 2> 38477 T47 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/core-home-001/'
[junit4] 2> 38587 T47 oasc.CoreContainer.<init> New CoreContainer 951190276
[junit4] 2> 38587 T47 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/core-home-001/]
[junit4] 2> 38589 T47 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 38590 T47 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 38590 T47 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 38591 T47 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 38591 T47 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 38592 T47 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 38592 T47 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 38593 T47 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 38594 T47 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 38596 T47 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=30000&connTimeout=30000&retry=false
[junit4] 2> 38598 T47 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 38599 T47 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 38601 T47 oasc.CoreContainer.load Host Name:
[junit4] 2> 38618 T49 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/core-home-001/collection1/'
[junit4] 2> 38719 T49 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 38800 T49 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4] 2> 38801 T49 oass.IndexSchema.readSchema Reading Solr Schema from dataimport-schema.xml
[junit4] 2> 38824 T49 oass.IndexSchema.readSchema [collection1] Schema name=dih_test
[junit4] 2> 38906 T49 oass.IndexSchema.readSchema default search field in schema is desc
[junit4] 2> 38908 T49 oass.IndexSchema.readSchema query parser default operator is OR
[junit4] 2> 38909 T49 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 38911 T49 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/core-home-001/collection1/
[junit4] 2> 38912 T49 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 38914 T49 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/core-home-001/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/
[junit4] 2> 38915 T49 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 38918 T49 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> 38919 T49 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 38921 T49 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001
[junit4] 2> 38922 T49 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index/
[junit4] 2> 38923 T49 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index' doesn't exist. Creating new index...
[junit4] 2> 38923 T49 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index
[junit4] 2> 38926 T49 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> 38926 T49 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 38930 T49 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "" (default)
[junit4] 2> 38930 T49 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "" (default)
[junit4] 2> 38932 T49 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 38932 T49 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 38933 T49 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 38934 T49 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 38934 T49 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 38935 T49 oasc.RequestHandlers.initHandlersFromConfig created /dataimport: org.apache.solr.handler.dataimport.DataImportHandler
[junit4] 2> 38936 T49 oasc.RequestHandlers.initHandlersFromConfig created /search: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 38936 T49 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 38937 T49 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 38954 T49 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 38956 T49 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 38959 T49 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 38962 T49 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 38965 T49 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 38969 T49 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 38970 T49 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 38971 T49 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> 38971 T49 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 38973 T49 oass.SolrIndexSearcher.<init> Opening Searcher@1b2ab82[collection1] main
[junit4] 2> 38974 T49 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/core-home-001/collection1/conf
[junit4] 2> 38975 T49 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/core-home-001/collection1/conf}
[junit4] 2> 38975 T49 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/core-home-001/collection1/conf
[junit4] 2> 38977 T49 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 38978 T49 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using file:dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/core-home-001/collection1/conf
[junit4] 2> 38979 T49 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 38980 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1b2ab82[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 38981 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 38982 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b2ab82[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 38980 T49 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 38990 T47 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 39004 T47 oas.SolrTestCaseJ4.setUp ###Starting testDeltaImportWithoutInitialFullImport
[junit4] 2> ASYNC NEW_CORE C3 name=collection1 org.apache.solr.core.SolrCore@576ec5d6
[junit4] 2> 39060 T47 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 39062 T47 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 45
[junit4] 2> 39082 T47 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 39084 T47 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_2,generation=2}
[junit4] 2> 39085 T47 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 39087 T47 C3 oass.SolrIndexSearcher.<init> Opening Searcher@5c60db37[collection1] main
[junit4] 2> 39089 T47 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 39090 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5c60db37[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 39090 T50 C3 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> 39091 T50 C3 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> 39092 T50 C3 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> 39092 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 39093 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c60db37[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 39094 T47 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 13
[junit4] 2> ASYNC NEW_CORE C4 name=collection1 org.apache.solr.core.SolrCore@576ec5d6
[junit4] 2> 39924 T47 C4 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 39925 T47 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 39926 T47 C4 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 39927 T47 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 40017 T47 C4 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 40028 T47 C4 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 40040 T47 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 40042 T47 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 40085 T47 C4 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 40088 T47 C4 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 20
[junit4] 2> 40089 T47 C4 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
[junit4] 2> 40090 T47 C4 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 40119 T47 C4 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 40120 T47 C4 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 40121 T47 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 40204 T47 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_3,generation=3}
[junit4] 2> 40205 T47 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 40259 T47 C4 oass.SolrIndexSearcher.<init> Opening Searcher@7b3b18b5[collection1] main
[junit4] 2> 40260 T47 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 40260 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7b3b18b5[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C20))}
[junit4] 2> 40261 T50 C4 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> 40262 T50 C4 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> 40263 T50 C4 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> 40264 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 40264 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7b3b18b5[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C20))}
[junit4] 2> 40265 T47 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 40267 T47 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 40269 T47 C4 oashd.DocBuilder.execute Time taken = 0:0:0.341
[junit4] 2> 40269 T47 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={command=delta-import&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-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&indent=true&synchronous=true&commit=true&clean=false} {add=[10, 11, 8, 9, 14, 15, 12, 13, 2, 3, ... (20 adds)],commit=} 0 358
[junit4] 2> 40273 T47 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=*:*&rows=20&start=0&version=2.2} hits=20 status=0 QTime=2
[junit4] 2> 40313 T47 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 40315 T47 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 40329 T47 oas.SolrTestCaseJ4.tearDown ###Ending testDeltaImportWithoutInitialFullImport
[junit4] 2> 40350 T47 oas.SolrTestCaseJ4.setUp ###Starting testWithComplexTransformer
[junit4] 2> 40352 T47 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 40352 T47 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 40360 T47 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 40364 T47 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_4,generation=4}
[junit4] 2> 40369 T47 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 40373 T47 C4 oass.SolrIndexSearcher.<init> Opening Searcher@18dbc02e[collection1] main
[junit4] 2> 40373 T47 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 40374 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@18dbc02e[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 40375 T50 C4 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> 40376 T50 C4 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> 40377 T50 C4 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> 40377 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 40378 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18dbc02e[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 40386 T47 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 26
[junit4] 2> ASYNC NEW_CORE C5 name=collection1 org.apache.solr.core.SolrCore@576ec5d6
[junit4] 2> 46157 T47 C5 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 46157 T47 C5 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 46158 T47 C5 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 46159 T47 C5 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 46160 T47 C5 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 46162 T47 C5 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 46165 T47 C5 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4] 2> 46602 T47 C5 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 46603 T47 C5 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 46639 T47 C5 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_5,generation=5}
[junit4] 2> 46640 T47 C5 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 46651 T47 C5 oass.SolrIndexSearcher.<init> Opening Searcher@5998f9bf[collection1] main
[junit4] 2> 46653 T47 C5 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 46654 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5998f9bf[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C60))}
[junit4] 2> 46655 T50 C5 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> 46656 T50 C5 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> 46660 T50 C5 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=4
[junit4] 2> 46661 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 46661 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5998f9bf[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C60))}
[junit4] 2> 46662 T47 C5 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 46663 T47 C5 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 46664 T47 C5 oashd.DocBuilder.execute Time taken = 0:0:0.503
[junit4] 2> 46664 T47 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={command=full-import&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-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"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&synchronous=true&commit=true&clean=true} {deleteByQuery=*:*,add=[1, TripleThreat-1-1, TripleThreat-2-1, 2, TripleThreat-1-2, TripleThreat-2-2, 3, TripleThreat-1-3, TripleThreat-2-3, 4, ... (60 adds)],commit=} 0 521
[junit4] 2> 47253 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=*:*&rows=60&sort=id+asc} hits=60 status=0 QTime=387
[junit4] 2> 47359 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:TripleThreat-1-*&rows=20&start=0&version=2.2} hits=20 status=0 QTime=36
[junit4] 2> 47371 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:TripleThreat-2-*&rows=20&start=0&version=2.2} hits=20 status=0 QTime=2
[junit4] 2> 47517 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&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&start=0&version=2.2} hits=1 status=0 QTime=62
[junit4] 2> 47525 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=AddAColumn_s:Added&rows=20&start=0&version=2.2} hits=20 status=0 QTime=3
[junit4] 2> 47535 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 47536 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 47537 T47 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 47700 T47 C5 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 47701 T47 C5 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 47701 T47 C5 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 47702 T47 C5 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 47704 T47 C5 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 47704 T47 C5 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 47705 T47 C5 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 47707 T47 C5 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4] 2> 47992 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 48008 T47 C5 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 7
[junit4] 2> 48009 T47 C5 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 6
[junit4] 2> 48009 T47 C5 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 48010 T47 C5 oashd.DocBuilder.deleteAll Deleting stale documents
[junit4] 2> 48011 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 48011 T47 C5 oashd.SolrWriter.deleteDoc Deleting document: 6
[junit4] 2> 48012 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 48013 T47 C5 oashd.SolrWriter.deleteDoc Deleting document: 7
[junit4] 2> 48014 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 48014 T47 C5 oashd.SolrWriter.deleteDoc Deleting document: 5
[junit4] 2> 48015 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 48016 T47 C5 oashd.SolrWriter.deleteDoc Deleting document: 1
[junit4] 2> 48017 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 48017 T47 C5 oashd.SolrWriter.deleteDoc Deleting document: 15
[junit4] 2> 48018 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 48018 T47 C5 oashd.SolrWriter.deleteDoc Deleting document: 12
[junit4] 2> 48128 T47 C5 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 48141 T47 C5 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 48144 T47 C5 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 48254 T47 C5 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_5,generation=5}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_6,generation=6}
[junit4] 2> 48255 T47 C5 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4] 2> 48277 T47 C5 oass.SolrIndexSearcher.<init> Opening Searcher@aac1284[collection1] main
[junit4] 2> 48279 T47 C5 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 48292 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@aac1284[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C60/24:delGen=1) Uninverting(_2(5.0):C21))}
[junit4] 2> 48292 T50 C5 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> 48294 T50 C5 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> 48295 T50 C5 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> 48296 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 48296 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@aac1284[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C60/24:delGen=1) Uninverting(_2(5.0):C21))}
[junit4] 2> 48298 T47 C5 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 48299 T47 C5 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 48300 T47 C5 oashd.DocBuilder.execute Time taken = 0:0:0.597
[junit4] 2> 48300 T47 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={command=delta-import&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-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"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&synchronous=true&commit=true&clean=false} {delete=[6, 7, 5, 1, 15, 12],add=[10, TripleThreat-1-10, TripleThreat-2-10, 1011, TripleThreat-1-1011, TripleThreat-2-1011, 11, TripleThreat-1-11, TripleThreat-2-11, 8, ... (21 adds)],commit=} 0 614
[junit4] 2> 48312 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=*:*&rows=45&sort=id+asc} hits=57 status=0 QTime=1
[junit4] 2> 48346 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:TripleThreat-1-*&rows=20&start=0&version=2.2} hits=21 status=0 QTime=1
[junit4] 2> 48357 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:TripleThreat-2-*&rows=20&start=0&version=2.2} hits=21 status=0 QTime=1
[junit4] 2> 48372 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=AddAColumn_s:Added&rows=20&start=0&version=2.2} hits=21 status=0 QTime=0
[junit4] 2> 48383 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 48383 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 48390 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:1011&rows=20&start=0&version=2.2} hits=1 status=0 QTime=4
[junit4] 2> 48398 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:12&rows=20&start=0&version=2.2} hits=0 status=0 QTime=2
[junit4] 2> 48402 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:15&rows=20&start=0&version=2.2} hits=0 status=0 QTime=1
[junit4] 2> 48419 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:5&rows=20&start=0&version=2.2} hits=0 status=0 QTime=1
[junit4] 2> 48424 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:6&rows=20&start=0&version=2.2} hits=0 status=0 QTime=1
[junit4] 2> 48431 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:7&rows=20&start=0&version=2.2} hits=0 status=0 QTime=3
[junit4] 2> 48446 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:1&rows=20&start=0&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 48451 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:20&rows=20&start=0&version=2.2} hits=1 status=0 QTime=1
[junit4] 2> 48458 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:19&rows=20&start=0&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 48473 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:3&rows=20&start=0&version=2.2} hits=1 status=0 QTime=5
[junit4] 2> 48488 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:8&rows=20&start=0&version=2.2} hits=1 status=0 QTime=4
[junit4] 2> 48494 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:10&rows=20&start=0&version=2.2} hits=1 status=0 QTime=1
[junit4] 2> 48501 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:11&rows=20&start=0&version=2.2} hits=1 status=0 QTime=1
[junit4] 2> 49246 T47 oas.SolrTestCaseJ4.tearDown ###Ending testWithComplexTransformer
[junit4] 2> 49262 T47 oas.SolrTestCaseJ4.setUp ###Starting testWithSimpleTransformer
[junit4] 2> 49264 T47 C5 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 49265 T47 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 49273 T47 C5 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 49275 T47 C5 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_6,generation=6}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_7,generation=7}
[junit4] 2> 49276 T47 C5 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 7
[junit4] 2> 49277 T47 C5 oass.SolrIndexSearcher.<init> Opening Searcher@2607841b[collection1] main
[junit4] 2> 49278 T47 C5 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 49280 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2607841b[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 49281 T50 C5 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> 49282 T50 C5 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> 49285 T50 C5 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=2
[junit4] 2> 49285 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 49286 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2607841b[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 49295 T47 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 22
[junit4] 2> 49351 T47 C5 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 49353 T47 C5 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 49353 T47 C5 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 49355 T47 C5 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 49356 T47 C5 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 49358 T47 C5 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 49358 T47 C5 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 49436 T47 C5 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 49437 T47 C5 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 49500 T47 C5 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_7,generation=7}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_8,generation=8}
[junit4] 2> 49501 T47 C5 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 8
[junit4] 2> 49505 T47 C5 oass.SolrIndexSearcher.<init> Opening Searcher@11839b3d[collection1] main
[junit4] 2> 49505 T47 C5 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 49514 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@11839b3d[collection1] main{UninvertingDirectoryReader(Uninverting(_3(5.0):C20))}
[junit4] 2> 49515 T50 C5 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> 49517 T50 C5 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> 49518 T50 C5 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> 49518 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 49519 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@11839b3d[collection1] main{UninvertingDirectoryReader(Uninverting(_3(5.0):C20))}
[junit4] 2> 49520 T47 C5 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 49521 T47 C5 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 49522 T47 C5 oashd.DocBuilder.execute Time taken = 0:0:0.165
[junit4] 2> 49522 T47 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={command=full-import&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-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&indent=true&synchronous=true&commit=true&clean=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 183
[junit4] 2> 49527 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=AddAColumn_s:Added&rows=20&start=0&version=2.2} hits=20 status=0 QTime=2
[junit4] 2> 49538 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 49539 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 49541 T47 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 49552 T47 C5 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 49552 T47 C5 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 49553 T47 C5 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 49554 T47 C5 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 49556 T47 C5 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 49556 T47 C5 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 49557 T47 C5 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 49557 T47 C5 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 49560 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 49562 T47 C5 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 3
[junit4] 2> 49562 T47 C5 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 5
[junit4] 2> 49563 T47 C5 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 49564 T47 C5 oashd.DocBuilder.deleteAll Deleting stale documents
[junit4] 2> 49565 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 49565 T47 C5 oashd.SolrWriter.deleteDoc Deleting document: 6
[junit4] 2> 49566 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 49566 T47 C5 oashd.SolrWriter.deleteDoc Deleting document: 13
[junit4] 2> 49567 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 49568 T47 C5 oashd.SolrWriter.deleteDoc Deleting document: 11
[junit4] 2> 49568 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 49568 T47 C5 oashd.SolrWriter.deleteDoc Deleting document: 20
[junit4] 2> 49569 T47 C5 oashd.DocBuilder.findMatchingPkColumn Resolving deltaQuery column 'ID' to match entity's declared pk 'People.ID'
[junit4] 2> 49569 T47 C5 oashd.SolrWriter.deleteDoc Deleting document: 9
[junit4] 2> 49573 T47 C5 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 49574 T47 C5 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 49574 T47 C5 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 49587 T47 C5 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_8,generation=8}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_9,generation=9}
[junit4] 2> 49588 T47 C5 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 9
[junit4] 2> 49646 T47 C5 oass.SolrIndexSearcher.<init> Opening Searcher@48de6eb1[collection1] main
[junit4] 2> 49647 T47 C5 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 49661 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@48de6eb1[collection1] main{UninvertingDirectoryReader(Uninverting(_3(5.0):C20/6:delGen=1) Uninverting(_4(5.0):C3))}
[junit4] 2> 49663 T50 C5 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> 49663 T50 C5 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> 49664 T50 C5 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> 49665 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 49665 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@48de6eb1[collection1] main{UninvertingDirectoryReader(Uninverting(_3(5.0):C20/6:delGen=1) Uninverting(_4(5.0):C3))}
[junit4] 2> 49668 T47 C5 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 49668 T47 C5 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 49669 T47 C5 oashd.DocBuilder.execute Time taken = 0:0:0.114
[junit4] 2> 49670 T47 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={command=delta-import&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-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&indent=true&synchronous=true&commit=true&clean=false} {delete=[6, 13, 11, 20, 9],add=[1017, 18, 1009],commit=} 0 122
[junit4] 2> 49677 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=AddAColumn_s:Added&rows=20&start=0&version=2.2} hits=17 status=0 QTime=3
[junit4] 2> 49688 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 49689 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 49693 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:1017&rows=20&start=0&version=2.2} hits=1 status=0 QTime=3
[junit4] 2> 49698 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:1009&rows=20&start=0&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 49703 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:6&rows=20&start=0&version=2.2} hits=0 status=0 QTime=1
[junit4] 2> 49707 T47 C5 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:20&rows=20&start=0&version=2.2} hits=0 status=0 QTime=1
[junit4] 2> ASYNC NEW_CORE C6 name=collection1 org.apache.solr.core.SolrCore@576ec5d6
[junit4] 2> 50011 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:11&rows=20&start=0&version=2.2} hits=0 status=0 QTime=1
[junit4] 2> 50034 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:9&rows=20&start=0&version=2.2} hits=0 status=0 QTime=4
[junit4] 2> 50037 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:13&rows=20&start=0&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 50041 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:18&rows=20&start=0&version=2.2} hits=1 status=0 QTime=1
[junit4] 2> 50047 T47 oas.SolrTestCaseJ4.tearDown ###Ending testWithSimpleTransformer
[junit4] 2> 50065 T47 oas.SolrTestCaseJ4.setUp ###Starting testSingleEntity
[junit4] 2> 50067 T47 C6 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 50069 T47 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4] 2> 50077 T47 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 50079 T47 C6 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_9,generation=9}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_a,generation=10}
[junit4] 2> 50080 T47 C6 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 10
[junit4] 2> 50081 T47 C6 oass.SolrIndexSearcher.<init> Opening Searcher@2579946b[collection1] main
[junit4] 2> 50082 T47 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 50083 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2579946b[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 50084 T50 C6 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> 50085 T50 C6 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> 50086 T50 C6 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> 50086 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 50087 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2579946b[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 50090 T47 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 13
[junit4] 2> 51032 T47 C6 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 51032 T47 C6 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 51033 T47 C6 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 51034 T47 C6 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 51035 T47 C6 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 51037 T47 C6 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 51039 T47 C6 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 51072 T47 C6 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 51073 T47 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 51084 T47 C6 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_a,generation=10}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_b,generation=11}
[junit4] 2> 51085 T47 C6 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 11
[junit4] 2> 51088 T47 C6 oass.SolrIndexSearcher.<init> Opening Searcher@49ee9bfa[collection1] main
[junit4] 2> 51092 T47 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 51100 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@49ee9bfa[collection1] main{UninvertingDirectoryReader(Uninverting(_5(5.0):C20))}
[junit4] 2> 51101 T50 C6 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> 51102 T50 C6 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> 51103 T50 C6 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> 51104 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 51105 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@49ee9bfa[collection1] main{UninvertingDirectoryReader(Uninverting(_5(5.0):C20))}
[junit4] 2> 51111 T47 C6 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 51117 T47 C6 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 51121 T47 C6 oashd.DocBuilder.execute Time taken = 0:0:0.86
[junit4] 2> 51125 T47 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={command=full-import&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-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&synchronous=true&commit=true&clean=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 132
[junit4] 2> 51141 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=*:*&rows=20&start=0&version=2.2} hits=20 status=0 QTime=3
[junit4] 2> 51152 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 51153 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 51154 T47 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 51198 T47 C6 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 51199 T47 C6 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 51199 T47 C6 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 51200 T47 C6 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 51206 T47 C6 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 51206 T47 C6 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 51207 T47 C6 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 51208 T47 C6 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 51244 T47 C6 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 3
[junit4] 2> 51245 T47 C6 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 3
[junit4] 2> 51245 T47 C6 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 51246 T47 C6 oashd.DocBuilder.deleteAll Deleting stale documents
[junit4] 2> 51246 T47 C6 oashd.SolrWriter.deleteDoc Deleting document: 12
[junit4] 2> 51247 T47 C6 oashd.SolrWriter.deleteDoc Deleting document: 5
[junit4] 2> 51248 T47 C6 oashd.SolrWriter.deleteDoc Deleting document: 20
[junit4] 2> 51278 T47 C6 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 51278 T47 C6 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 51279 T47 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 51295 T47 C6 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_b,generation=11}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_c,generation=12}
[junit4] 2> 51296 T47 C6 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 12
[junit4] 2> 51300 T47 C6 oass.SolrIndexSearcher.<init> Opening Searcher@36f243b1[collection1] main
[junit4] 2> 51302 T47 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 51310 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@36f243b1[collection1] main{UninvertingDirectoryReader(Uninverting(_5(5.0):C20/6:delGen=1) Uninverting(_6(5.0):C3))}
[junit4] 2> 51311 T50 C6 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> 51311 T50 C6 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> 51312 T50 C6 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> 51313 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 51314 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36f243b1[collection1] main{UninvertingDirectoryReader(Uninverting(_5(5.0):C20/6:delGen=1) Uninverting(_6(5.0):C3))}
[junit4] 2> 51315 T47 C6 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 51316 T47 C6 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 51317 T47 C6 oashd.DocBuilder.execute Time taken = 0:0:0.114
[junit4] 2> 51317 T47 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={command=delta-import&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-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&synchronous=true&commit=true&clean=false} {delete=[12, 5, 20],add=[4, 18, 1],commit=} 0 123
[junit4] 2> 51326 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=*:*&rows=20&start=0&version=2.2} hits=17 status=0 QTime=5
[junit4] 2> 51337 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 51338 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 51339 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:12&rows=20&start=0&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 51342 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:5&rows=20&start=0&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 51345 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:20&rows=20&start=0&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 51363 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:4&rows=20&start=0&version=2.2} hits=1 status=0 QTime=4
[junit4] 2> 51367 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:18&rows=20&start=0&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 51378 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=id:1&rows=20&start=0&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 51905 T47 oas.SolrTestCaseJ4.tearDown ###Ending testSingleEntity
[junit4] 2> 51930 T47 oas.SolrTestCaseJ4.setUp ###Starting testChildEntities
[junit4] 2> 51933 T47 C6 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 51934 T47 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 51939 T47 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 51940 T47 C6 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_c,generation=12}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_d,generation=13}
[junit4] 2> 51941 T47 C6 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 13
[junit4] 2> 51941 T47 C6 oass.SolrIndexSearcher.<init> Opening Searcher@5db95566[collection1] main
[junit4] 2> 51943 T47 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 51944 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5db95566[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 51945 T50 C6 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> 51946 T50 C6 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> 51948 T50 C6 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=2
[junit4] 2> 51948 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 51950 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5db95566[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 51958 T47 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 18
[junit4] 2> 52034 T47 C6 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 52034 T47 C6 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 52035 T47 C6 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 52036 T47 C6 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 52037 T47 C6 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 52038 T47 C6 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 52040 T47 C6 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 52041 T47 C6 oashd.JdbcDataSource$1.call Creating a connection for entity Countries with URL: jdbc:hsqldb:mem:.
[junit4] 2> 52041 T47 C6 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 52066 T47 C6 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 52066 T47 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 52134 T47 C6 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_d,generation=13}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_e,generation=14}
[junit4] 2> 52136 T47 C6 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 14
[junit4] 2> 52145 T47 C6 oass.SolrIndexSearcher.<init> Opening Searcher@257ccde[collection1] main
[junit4] 2> 52147 T47 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 52159 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@257ccde[collection1] main{UninvertingDirectoryReader(Uninverting(_7(5.0):C20))}
[junit4] 2> 52160 T50 C6 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> 52160 T50 C6 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> 52161 T50 C6 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> 52161 T50 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 52161 T50 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@257ccde[collection1] main{UninvertingDirectoryReader(Uninverting(_7(5.0):C20))}
[junit4] 2> 52162 T47 C6 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 52163 T47 C6 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 52164 T47 C6 oashd.DocBuilder.execute Time taken = 0:0:0.127
[junit4] 2> 52165 T47 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={command=full-import&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-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+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&indent=true&synchronous=true&commit=true&clean=true} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 155
[junit4] 2> 52168 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=*:*&rows=20&start=0&version=2.2} hits=20 status=0 QTime=2
[junit4] 2> 52181 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=NAME_mult_s:Jayden&rows=20&start=0&version=2.2} hits=1 status=0 QTime=1
[junit4] 2> 52187 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=COUNTRY_CODES_mult_s:NR&rows=20&start=0&version=2.2} hits=2 status=0 QTime=2
[junit4] 2> 52197 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=countryAdded_s:country_added&rows=20&start=0&version=2.2} hits=20 status=0 QTime=2
[junit4] 2> 52208 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 52209 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 52209 T47 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 52214 T47 C6 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 52216 T47 C6 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 52216 T47 C6 oashd.DataImporter.doDeltaImport Starting Delta Import
[junit4] 2> 52217 T47 C6 oashd.SimplePropertiesWriter.readIndexerProperties Read the.properties
[junit4] 2> 52219 T47 C6 oashd.DocBuilder.doDelta Starting delta collection.
[junit4] 2> 52220 T47 C6 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: Countries
[junit4] 2> 52220 T47 C6 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: Countries rows obtained : 0
[junit4] 2> 52221 T47 C6 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: Countries rows obtained : 0
[junit4] 2> 52221 T47 C6 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: Countries
[junit4] 2> 52222 T47 C6 oashd.DocBuilder.collectDelta Running ModifiedRowKey() for Entity: People
[junit4] 2> 52223 T47 C6 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 52223 T47 C6 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 52227 T47 C6 oashd.DocBuilder.collectDelta Completed ModifiedRowKey for Entity: People rows obtained : 6
[junit4] 2> 52227 T47 C6 oashd.DocBuilder.collectDelta Completed DeletedRowKey for Entity: People rows obtained : 0
[junit4] 2> 52228 T47 C6 oashd.DocBuilder.collectDelta Completed parentDeltaQuery for Entity: People
[junit4] 2> 52230 T47 C6 oashd.JdbcDataSource$1.call Creating a connection for entity Countries with URL: jdbc:hsqldb:mem:.
[junit4] 2> 52231 T47 C6 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 52240 T47 C6 oashd.DocBuilder.doDelta Delta Import completed successfully
[junit4] 2> 52240 T47 C6 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 52240 T47 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 52252 T47 C6 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@66656827 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index),segFN=segments_e,generat
[...truncated too long message...]
le.last_index_time}')+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a<entity+name%3D"Countries"+pk%3D"CODE"+dataSource%3D"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&indent=true&synchronous=true&commit=true&clean=false} {add=[13, 3, 10, 20, 15, 8],commit=} 0 65
[junit4] 2> 52281 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=*:*&rows=20&start=0&version=2.2} hits=20 status=0 QTime=3
[junit4] 2> 52304 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=NAME_mult_s:Jayden&rows=20&start=0&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 52311 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=COUNTRY_CODES_mult_s:NR&rows=20&start=0&version=2.2} hits=2 status=0 QTime=1
[junit4] 2> 52319 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=COUNTRY_CODE_s:NR&rows=20&start=0&version=2.2} hits=2 status=0 QTime=3
[junit4] 2> 52327 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=COUNTRY_CODE_s:NE&rows=20&start=0&version=2.2} hits=2 status=0 QTime=3
[junit4] 2> 52336 T47 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&q=COUNTRY_CODE_s:NG&rows=20&start=0&version=2.2} hits=2 status=0 QTime=3
[junit4] 2> 52343 T47 oas.SolrTestCaseJ4.tearDown ###Ending testChildEntities
[junit4] 2> 52464 T47 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 52465 T47 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=951190276
[junit4] 2> 52466 T47 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@576ec5d6
[junit4] 2> 52467 T47 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=14,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=173,cumulative_deletesById=14,cumulative_deletesByQuery=9,cumulative_errors=0}
[junit4] 2> 52467 T47 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 52469 T47 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 52470 T47 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 52476 T47 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 52477 T47 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 52478 T47 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index;done=false>>]
[junit4] 2> 52478 T47 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001/index
[junit4] 2> 52479 T47 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001 [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001;done=false>>]
[junit4] 2> 52479 T47 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessorDelta-AF00CD81A18CE2F6-001/init-core-data-001
[junit4] 2> 17682 T46 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> 37758 T46 ccr.ThreadLeakControl.checkThreadLeaks SEVERE 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta:
[junit4] 2> 1) Thread[id=48, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta]
[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> 37759 T46 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=48, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta]
[junit4] 2> 40779 T46 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=48, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta]
[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: {COUNTRY_CODE_s=FSTOrd41, COUNTRY_NAME_s=FSTOrd41, COUNTRY_CODES_mult_s=PostingsFormat(name=NestedPulsing), NAME_mult_s=PostingsFormat(name=NestedPulsing), id=PostingsFormat(name=Lucene41WithOrds), countryAdded_s=FSTOrd41, AddAColumn_s=FSTOrd41, timestamp=FSTOrd41}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=ko, timezone=America/Rainy_River
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_65 (64-bit)/cpus=2,threads=2,free=29943496,total=112721920
[junit4] 2> NOTE: All tests run in this JVM: [TestScriptTransformer, TestContextImpl, TestPlainTextEntityProcessor, TestContentStreamDataSource, TestSqlEntityProcessorDelta]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestSqlEntityProcessorDelta -Dtests.seed=AF00CD81A18CE2F6 -Dtests.slow=true -Dtests.locale=ko -Dtests.timezone=America/Rainy_River -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s | TestSqlEntityProcessorDelta (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSqlEntityProcessorDelta:
[junit4] > 1) Thread[id=48, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta]
[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([AF00CD81A18CE2F6]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=48, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessorDelta]
[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([AF00CD81A18CE2F6]:0)
[junit4] Completed in 40.97s, 5 tests, 2 errors <<< FAILURES!
[...truncated 105 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:474: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:454: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:209: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:440: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1307: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:922: There were test failures: 37 suites, 148 tests, 2 suite-level errors, 128 ignored
Total time: 180 minutes 5 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.8.0) - Build # 1762
- Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1762/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseParallelGC
2 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestSqlEntityProcessor
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSqlEntityProcessor: 1) Thread[id=23, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessor] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) 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.TestSqlEntityProcessor:
1) Thread[id=23, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessor]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([AA9C2328B9352DCA]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.handler.dataimport.TestSqlEntityProcessor
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=23, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessor] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) 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=23, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessor]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([AA9C2328B9352DCA]:0)
Build Log:
[...truncated 14997 lines...]
[junit4] Suite: org.apache.solr.handler.dataimport.TestSqlEntityProcessor
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001
[junit4] 2> 20111 T22 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 24590 T22 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 24593 T22 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/core-home-001/collection1/'
[junit4] 2> 24672 T22 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 24842 T22 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4] 2> 24844 T22 oass.IndexSchema.readSchema Reading Solr Schema from dataimport-schema.xml
[junit4] 2> 24869 T22 oass.IndexSchema.readSchema [null] Schema name=dih_test
[junit4] 2> 24901 T22 oass.IndexSchema.readSchema default search field in schema is desc
[junit4] 2> 24903 T22 oass.IndexSchema.readSchema query parser default operator is OR
[junit4] 2> 24904 T22 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 24907 T22 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 24907 T22 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/core-home-001
[junit4] 2> 24908 T22 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/core-home-001/'
[junit4] 2> 24957 T22 oasc.CoreContainer.<init> New CoreContainer 1499987693
[junit4] 2> 24958 T22 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/core-home-001/]
[junit4] 2> 24959 T22 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 24961 T22 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 24962 T22 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 24963 T22 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 24963 T22 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 24963 T22 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 24964 T22 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 24965 T22 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 24966 T22 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 25122 T22 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=30000&connTimeout=30000&retry=false
[junit4] 2> 25126 T22 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 25127 T22 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 25127 T22 oasc.CoreContainer.load Host Name:
[junit4] 2> 25139 T24 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/core-home-001/collection1/'
[junit4] 2> 25246 T24 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 25281 T24 oasc.SolrConfig.<init> Loaded SolrConfig: dataimport-solrconfig.xml
[junit4] 2> 25282 T24 oass.IndexSchema.readSchema Reading Solr Schema from dataimport-schema.xml
[junit4] 2> 25301 T24 oass.IndexSchema.readSchema [collection1] Schema name=dih_test
[junit4] 2> 25327 T24 oass.IndexSchema.readSchema default search field in schema is desc
[junit4] 2> 25328 T24 oass.IndexSchema.readSchema query parser default operator is OR
[junit4] 2> 25328 T24 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 25329 T24 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/core-home-001/collection1/
[junit4] 2> 25330 T24 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 25330 T24 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/core-home-001/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/
[junit4] 2> 25331 T24 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 25331 T24 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> 25332 T24 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 25347 T24 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001
[junit4] 2> 25349 T24 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index/
[junit4] 2> 25349 T24 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index' doesn't exist. Creating new index...
[junit4] 2> 25350 T24 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index
[junit4] 2> 25390 T24 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> 25391 T24 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 25394 T24 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "" (default)
[junit4] 2> 25509 T24 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "" (default)
[junit4] 2> 25510 T24 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 25511 T24 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 25512 T24 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 25512 T24 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 25512 T24 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 25513 T24 oasc.RequestHandlers.initHandlersFromConfig created /dataimport: org.apache.solr.handler.dataimport.DataImportHandler
[junit4] 2> 25513 T24 oasc.RequestHandlers.initHandlersFromConfig created /search: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 25514 T24 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 25514 T24 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 25524 T24 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 25530 T24 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 25532 T24 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 25540 T24 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 25543 T24 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 25546 T24 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 25546 T24 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 25550 T24 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> 25550 T24 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 25551 T24 oass.SolrIndexSearcher.<init> Opening Searcher@2fe32b09[collection1] main
[junit4] 2> 25552 T24 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/core-home-001/collection1/conf
[junit4] 2> 25553 T24 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/core-home-001/collection1/conf}
[junit4] 2> 25555 T24 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/core-home-001/collection1/conf
[junit4] 2> 25556 T24 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 25558 T24 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using file:dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/core-home-001/collection1/conf
[junit4] 2> 25559 T24 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 25559 T24 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 25559 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2fe32b09[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 25561 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 25562 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2fe32b09[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 25567 T22 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 25586 T22 oas.SolrTestCaseJ4.setUp ###Starting testCachedChildEntities
[junit4] 2> ASYNC NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@77d64a30
[junit4] 2> 25987 T22 C2 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 25995 T22 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 397
[junit4] 2> 26010 T22 C2 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 26013 T22 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_2,generation=2}
[junit4] 2> 26014 T22 C2 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 26015 T22 C2 oass.SolrIndexSearcher.<init> Opening Searcher@2b8545a8[collection1] main
[junit4] 2> 26018 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2b8545a8[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 26022 T22 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 26024 T25 C2 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=6
[junit4] 2> 26025 T25 C2 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 26027 T25 C2 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> 26027 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 26027 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2b8545a8[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 26028 T22 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 18
[junit4] 2> ASYNC NEW_CORE C3 name=collection1 org.apache.solr.core.SolrCore@77d64a30
[junit4] 2> 31947 T22 C3 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 31949 T22 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 31956 T22 C3 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 31957 T22 C3 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 32225 T22 C3 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [CachedSqlEntityProcessor]. Please consult documentation how to replace it accordingly.
[junit4] 2> 32226 T22 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 32244 T22 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 32249 T22 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 3
[junit4] 2> 32702 T22 C3 oashd.JdbcDataSource$1.call Creating a connection for entity Countries with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 32706 T22 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 3
[junit4] 2> 32926 T22 C3 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 32930 T22 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 32961 T22 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_3,generation=3}
[junit4] 2> 32965 T22 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 32968 T22 C3 oass.SolrIndexSearcher.<init> Opening Searcher@22ecd8e8[collection1] main
[junit4] 2> 32972 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@22ecd8e8[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C20))}
[junit4] 2> 32973 T25 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 32974 T25 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 32975 T25 C3 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> 32976 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 32976 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@22ecd8e8[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C20))}
[junit4] 2> 32976 T22 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 32978 T22 C3 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 32979 T22 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 32980 T22 C3 oashd.DocBuilder.execute Time taken = 0:0:1.21
[junit4] 2> 32981 T22 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={indent=true&synchronous=true&commit=true&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-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'+"+>+%0a<field+column%3D"NAME"+name%3D"NAME_mult_s"+/>+%0a<field+column%3D"COUNTRY_CODE"+name%3D"COUNTRY_CODES_mult_s"+/>+%0a<entity+name%3D"Countries"+pk%3D"Countries.CODE"+dataSource%3D"derby"+transformer%3D"AddAColumnTransformer"+newColumnName%3D"countryAdded_s"+newColumnValue%3D"country_added"+processor%3D"CachedSqlEntityProcessor"+where%3D"CODE%3DPeople.COUNTRY_CODE"+query%3D"SELECT+CODE,+COUNTRY_NAME+FROM+COUNTRIES"+>+%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&clean=true&command=full-import} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 1055
[junit4] 2> 33154 T22 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=*:*&qt=standard&start=0&rows=20&version=2.2} hits=20 status=0 QTime=12
[junit4] 2> 33176 T22 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=AddAColumn_s:Added&qt=standard&start=0&rows=20&version=2.2} hits=20 status=0 QTime=6
[junit4] 2> 33265 T22 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=NAME_mult_s:Jayden&qt=standard&start=0&rows=20&version=2.2} hits=1 status=0 QTime=1
[junit4] 2> 33342 T22 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=COUNTRY_CODES_mult_s:NR&qt=standard&start=0&rows=20&version=2.2} hits=2 status=0 QTime=1
[junit4] 2> 33352 T22 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=countryAdded_s:country_added&qt=standard&start=0&rows=20&version=2.2} hits=20 status=0 QTime=5
[junit4] 2> 33360 T22 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 33361 T22 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 34005 T22 oas.SolrTestCaseJ4.tearDown ###Ending testCachedChildEntities
[junit4] 2> 34025 T22 oas.SolrTestCaseJ4.setUp ###Starting testWithComplexTransformer
[junit4] 2> 34029 T22 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 34030 T22 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4] 2> 34033 T22 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 34036 T22 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_4,generation=4}
[junit4] 2> 34036 T22 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 34040 T22 C3 oass.SolrIndexSearcher.<init> Opening Searcher@5500a382[collection1] main
[junit4] 2> 34042 T22 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 34043 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5500a382[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 34045 T25 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 34046 T25 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 34048 T25 C3 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> 34048 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 34049 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5500a382[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 34053 T22 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 20
[junit4] 2> 34667 T22 C3 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 34668 T22 C3 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 34668 T22 C3 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 34670 T22 C3 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 34671 T22 C3 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 34673 T22 C3 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 34677 T22 C3 oashd.JdbcDataSource$1.call Time taken for getConnection(): 1
[junit4] 2> 34939 T22 C3 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 34940 T22 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 34999 T22 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_5,generation=5}
[junit4] 2> 35000 T22 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 35004 T22 C3 oass.SolrIndexSearcher.<init> Opening Searcher@3dbc2fc3[collection1] main
[junit4] 2> 35006 T22 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 35017 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3dbc2fc3[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C60))}
[junit4] 2> 35018 T25 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 35019 T25 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 35021 T25 C3 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> 35021 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 35021 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3dbc2fc3[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C60))}
[junit4] 2> 35023 T22 C3 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 35025 T22 C3 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 35026 T22 C3 oashd.DocBuilder.execute Time taken = 0:0:0.355
[junit4] 2> 35027 T22 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={indent=true&synchronous=true&commit=true&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-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"TripleThreatTransformer"+query%3D"SELECT+ID,+NAME,+COUNTRY_CODE+FROM+PEOPLE+WHERE+DELETED+!%3D+'Y'+"+>+%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&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 375
[junit4] 2> 35626 T22 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=*:*&sort=id+asc&rows=60} hits=60 status=0 QTime=563
[junit4] 2> 35701 T22 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:TripleThreat-1-*&qt=standard&start=0&rows=20&version=2.2} hits=20 status=0 QTime=44
[junit4] 2> 35709 T22 C3 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:TripleThreat-2-*&qt=standard&start=0&rows=20&version=2.2} hits=20 status=0 QTime=2
[junit4] 2> ASYNC NEW_CORE C4 name=collection1 org.apache.solr.core.SolrCore@77d64a30
[junit4] 2> 35832 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=%2Bid:TripleThreat-1-3+%2BNAME_mult_s:Michael+%2BNAME_mult_s:leahciM++%2BCOUNTRY_CODES_mult_s:NR+%2BCOUNTRY_CODES_mult_s:RN&qt=standard&start=0&rows=20&version=2.2} hits=1 status=0 QTime=34
[junit4] 2> 35835 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=AddAColumn_s:Added&qt=standard&start=0&rows=20&version=2.2} hits=20 status=0 QTime=0
[junit4] 2> 35840 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 35841 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 36374 T22 oas.SolrTestCaseJ4.tearDown ###Ending testWithComplexTransformer
[junit4] 2> 36387 T22 oas.SolrTestCaseJ4.setUp ###Starting testChildEntities
[junit4] 2> 36389 T22 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 36390 T22 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 36392 T22 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 36393 T22 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_5,generation=5}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_6,generation=6}
[junit4] 2> 36394 T22 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4] 2> 36395 T22 C4 oass.SolrIndexSearcher.<init> Opening Searcher@558ee1bf[collection1] main
[junit4] 2> 36397 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@558ee1bf[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 36399 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 36400 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 36400 T25 C4 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> 36401 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 36401 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@558ee1bf[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 36402 T22 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 36407 T22 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 15
[junit4] 2> 37143 T22 C4 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 37144 T22 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 37144 T22 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 37145 T22 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 37146 T22 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 37148 T22 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 37149 T22 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 37163 T22 C4 oashd.JdbcDataSource$1.call Creating a connection for entity Countries with URL: jdbc:hsqldb:mem:.
[junit4] 2> 37163 T22 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 37196 T22 C4 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 37197 T22 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 37237 T22 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_6,generation=6}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_7,generation=7}
[junit4] 2> 37239 T22 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 7
[junit4] 2> 37308 T22 C4 oass.SolrIndexSearcher.<init> Opening Searcher@5c489ed4[collection1] main
[junit4] 2> 37316 T22 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 37316 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5c489ed4[collection1] main{UninvertingDirectoryReader(Uninverting(_2(5.0):C20))}
[junit4] 2> 37318 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 37319 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 37319 T25 C4 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> 37320 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 37320 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c489ed4[collection1] main{UninvertingDirectoryReader(Uninverting(_2(5.0):C20))}
[junit4] 2> 37320 T22 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 37322 T22 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 37322 T22 C4 oashd.DocBuilder.execute Time taken = 0:0:0.176
[junit4] 2> 37323 T22 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={indent=true&synchronous=true&commit=true&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-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'+"+>+%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"+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&clean=true&command=full-import} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 187
[junit4] 2> 37328 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=*:*&qt=standard&start=0&rows=20&version=2.2} hits=20 status=0 QTime=3
[junit4] 2> 37336 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=AddAColumn_s:Added&qt=standard&start=0&rows=20&version=2.2} hits=20 status=0 QTime=1
[junit4] 2> 37352 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=NAME_mult_s:Jayden&qt=standard&start=0&rows=20&version=2.2} hits=1 status=0 QTime=1
[junit4] 2> 37362 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=COUNTRY_CODES_mult_s:NR&qt=standard&start=0&rows=20&version=2.2} hits=2 status=0 QTime=1
[junit4] 2> 37365 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 37366 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 37384 T22 oas.SolrTestCaseJ4.tearDown ###Ending testChildEntities
[junit4] 2> 37403 T22 oas.SolrTestCaseJ4.setUp ###Starting testSingleEntity
[junit4] 2> 37406 T22 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 37406 T22 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 37408 T22 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 37409 T22 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_7,generation=7}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_8,generation=8}
[junit4] 2> 37410 T22 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 8
[junit4] 2> 37414 T22 C4 oass.SolrIndexSearcher.<init> Opening Searcher@503f2749[collection1] main
[junit4] 2> 37416 T22 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 37417 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@503f2749[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 37418 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 37419 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 37420 T25 C4 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> 37420 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 37420 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@503f2749[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 37423 T22 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 15
[junit4] 2> 37465 T22 C4 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 37466 T22 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 37467 T22 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 37468 T22 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 37468 T22 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 37470 T22 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:hsqldb:mem:.
[junit4] 2> 37472 T22 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 37483 T22 C4 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 37484 T22 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 37488 T22 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_8,generation=8}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_9,generation=9}
[junit4] 2> 37488 T22 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 9
[junit4] 2> 37505 T22 C4 oass.SolrIndexSearcher.<init> Opening Searcher@74f311be[collection1] main
[junit4] 2> 37510 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@74f311be[collection1] main{UninvertingDirectoryReader(Uninverting(_3(5.0):C20))}
[junit4] 2> 37511 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 37511 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 37513 T25 C4 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> 37513 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 37514 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@74f311be[collection1] main{UninvertingDirectoryReader(Uninverting(_3(5.0):C20))}
[junit4] 2> 37514 T22 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 37515 T22 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 37516 T22 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 37516 T22 C4 oashd.DocBuilder.execute Time taken = 0:0:0.48
[junit4] 2> 37518 T22 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={indent=true&synchronous=true&commit=true&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-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'+"+>+%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&clean=true&command=full-import} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 58
[junit4] 2> 37524 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=*:*&qt=standard&start=0&rows=20&version=2.2} hits=20 status=0 QTime=4
[junit4] 2> 37530 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 37531 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 37533 T22 oas.SolrTestCaseJ4.tearDown ###Ending testSingleEntity
[junit4] 2> 37564 T22 oas.SolrTestCaseJ4.setUp ###Starting testWithSimpleTransformer
[junit4] 2> 37566 T22 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 37567 T22 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 37569 T22 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 37572 T22 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_9,generation=9}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_a,generation=10}
[junit4] 2> 37574 T22 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 10
[junit4] 2> 37574 T22 C4 oass.SolrIndexSearcher.<init> Opening Searcher@5a2359f[collection1] main
[junit4] 2> 37574 T22 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 37577 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5a2359f[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 37578 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 37579 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 37579 T25 C4 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> 37580 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 37580 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5a2359f[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 37598 T22 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 31
[junit4] 2> 37930 T22 C4 oashdc.DIHConfiguration.verifyWithSchema id is a required field in SolrSchema . But not found in DataConfig
[junit4] 2> 37932 T22 C4 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 37932 T22 C4 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 37934 T22 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 37934 T22 C4 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 37936 T22 C4 oashd.JdbcDataSource$1.call Creating a connection for entity People with URL: jdbc:derby:memory:derbyDB;territory=en_US
[junit4] 2> 37938 T22 C4 oashd.JdbcDataSource$1.call Time taken for getConnection(): 0
[junit4] 2> 37962 T22 C4 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 37963 T22 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 37993 T22 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_a,generation=10}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@2afff326 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index),segFN=segments_b,generation=11}
[junit4] 2> 37994 T22 C4 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 11
[junit4] 2> 37997 T22 C4 oass.SolrIndexSearcher.<init> Opening Searcher@2b7858ad[collection1] main
[junit4] 2> 37998 T22 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 38000 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2b7858ad[collection1] main{UninvertingDirectoryReader(Uninverting(_4(5.0):C20))}
[junit4] 2> 38001 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 38001 T25 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 38002 T25 C4 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> 38002 T25 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 38003 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2b7858ad[collection1] main{UninvertingDirectoryReader(Uninverting(_4(5.0):C20))}
[junit4] 2> 38004 T22 C4 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: the.properties
[junit4] 2> 38005 T22 C4 oashd.SimplePropertiesWriter.persist Wrote last indexed time to the.properties
[junit4] 2> 38006 T22 C4 oashd.DocBuilder.execute Time taken = 0:0:0.72
[junit4] 2> 38007 T22 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={indent=true&synchronous=true&commit=true&dataConfig=%0a<dataConfig>+%0a<propertyWriter+type%3D"SimplePropertiesWriter"+directory%3D"/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-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'+"+>+%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&clean=true&command=full-import} {deleteByQuery=*:*,add=[1, 2, 3, 4, 5, 6, 7, 8, 9, 10, ... (20 adds)],commit=} 0 82
[junit4] 2> 38025 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=AddAColumn_s:Added&qt=standard&start=0&rows=20&version=2.2} hits=20 status=0 QTime=4
[junit4] 2> 38034 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=1
[junit4] 2> 38034 T22 C4 oasc.SolrCore.execute [collection1] webapp=null path=null params={indent=true} status=0 QTime=0
[junit4] 2> 38545 T22 oas.SolrTestCaseJ4.tearDown ###Ending testWithSimpleTransformer
[junit4] 2> 38665 T22 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 38665 T22 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1499987693
[junit4] 2> 38666 T22 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@77d64a30
[junit4] 2> 38667 T22 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=10,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=140,cumulative_deletesById=0,cumulative_deletesByQuery=10,cumulative_errors=0}
[junit4] 2> 38667 T22 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 38667 T22 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 38667 T22 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 38673 T22 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 38678 T22 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 38678 T22 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001 [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001;done=false>>]
[junit4] 2> 38679 T22 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001
[junit4] 2> 38680 T22 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index;done=false>>]
[junit4] 2> 38680 T22 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/contrib/solr-dataimporthandler/test/J0/./temp/solr.handler.dataimport.TestSqlEntityProcessor-AA9C2328B9352DCA-001/init-core-data-001/index
[junit4] 2> 18648 T21 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> 38686 T21 ccr.ThreadLeakControl.checkThreadLeaks SEVERE 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSqlEntityProcessor:
[junit4] 2> 1) Thread[id=23, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessor]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:502)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> 38689 T21 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=23, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessor]
[junit4] 2> 41707 T21 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=23, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessor]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:502)
[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=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=331), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=331)), sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=sr_RS_#Latn, timezone=Asia/Jayapura
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_11 (64-bit)/cpus=2,threads=2,free=15893240,total=100663296
[junit4] 2> NOTE: All tests run in this JVM: [TestWriterImpl, TestDateFormatTransformer, TestBuiltInEvaluators, TestURLDataSource, TestSqlEntityProcessor]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestSqlEntityProcessor -Dtests.seed=AA9C2328B9352DCA -Dtests.slow=true -Dtests.locale=sr_RS_#Latn -Dtests.timezone=Asia/Jayapura -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s | TestSqlEntityProcessor (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.handler.dataimport.TestSqlEntityProcessor:
[junit4] > 1) Thread[id=23, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessor]
[junit4] > at java.lang.Object.wait(Native Method)
[junit4] > at java.lang.Object.wait(Object.java:502)
[junit4] > at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] > at java.util.TimerThread.run(Timer.java:505)
[junit4] > at __randomizedtesting.SeedInfo.seed([AA9C2328B9352DCA]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=23, name=Timer-0, state=WAITING, group=TGRP-TestSqlEntityProcessor]
[junit4] > at java.lang.Object.wait(Native Method)
[junit4] > at java.lang.Object.wait(Object.java:502)
[junit4] > at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] > at java.util.TimerThread.run(Timer.java:505)
[junit4] > at __randomizedtesting.SeedInfo.seed([AA9C2328B9352DCA]:0)
[junit4] Completed in 41.92s, 6 tests, 2 errors, 1 skipped <<< FAILURES!
[...truncated 105 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:474: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:454: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:209: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:440: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1307: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:922: There were test failures: 37 suites, 148 tests, 2 suite-level errors, 130 ignored
Total time: 169 minutes 59 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any