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 2013/08/19 12:31:32 UTC
[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.8.0-ea-b102) -
Build # 3166 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3166/
Java: 64bit/jdk1.8.0-ea-b102 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest.testAddDelete
Error Message:
IOException occured when talking to server at: https://127.0.0.1:52764/solr/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:52764/solr/collection1
at __randomizedtesting.SeedInfo.seed([2358F4A026812AF9:EBB889AAD729F92F]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:436)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer.request(ConcurrentUpdateSolrServer.java:256)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
at org.apache.solr.client.solrj.SolrExampleTests.testAddDelete(SolrExampleTests.java:750)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:491)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Caused by: org.apache.http.NoHttpResponseException: The target server failed to respond
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:95)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
... 46 more
Build Log:
[...truncated 10595 lines...]
[junit4] Suite: org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest
[junit4] 2> 75288 T103 oas.SolrJettyTestBase.beforeSolrJettyTestBase Randomized ssl (true) and clientAuth (false)
[junit4] 2> 75288 T103 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\.\solrtest-SolrExampleStreamingBinaryTest-1376907862775
[junit4] 2> 75291 T103 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 75309 T103 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 75772 T103 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 75807 T103 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:52764
[junit4] 2> 75808 T103 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 75808 T103 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 75809 T103 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr
[junit4] 2> 75809 T103 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\'
[junit4] 2> 75848 T103 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\solr.xml
[junit4] 2> 75866 T103 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 75866 T103 oasc.CoreContainer.<init> New CoreContainer 1254698095
[junit4] 2> 75867 T103 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\]
[junit4] 2> 75867 T103 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 75867 T103 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 75867 T103 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 75868 T103 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 75868 T103 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 75868 T103 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 75868 T103 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 75869 T103 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 75869 T103 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 75869 T103 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 75882 T103 oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr
[junit4] 2> 75893 T103 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\
[junit4] 2> 75896 T103 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 75897 T113 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1
[junit4] 2> 75897 T113 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\'
[junit4] 2> 75933 T113 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 75934 T113 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\contrib\extraction\lib).
[junit4] 2> 75936 T113 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\dist).
[junit4] 2> 75937 T113 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\contrib\clustering\lib).
[junit4] 2> 75938 T113 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\dist).
[junit4] 2> 75939 T113 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\contrib\langid\lib).
[junit4] 2> 75940 T113 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\dist).
[junit4] 2> 75941 T113 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\contrib\velocity\lib).
[junit4] 2> 75942 T113 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\..\..\..\dist).
[junit4] 2> 75975 T113 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
[junit4] 2> 75978 T113 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 76014 T113 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 76015 T113 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 76028 T113 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 76296 T113 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 76330 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 76336 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 76361 T113 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 76361 T113 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleStreamingBinaryTest-1376907862775\
[junit4] 2> 76361 T113 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7761bdbc
[junit4] 2> 76361 T113 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 76361 T113 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
[junit4] 2> 76362 T113 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleStreamingBinaryTest-1376907862775\
[junit4] 2> 76363 T113 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleStreamingBinaryTest-1376907862775\index/
[junit4] 2> 76363 T113 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleStreamingBinaryTest-1376907862775\index' doesn't exist. Creating new index...
[junit4] 2> 76363 T113 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleStreamingBinaryTest-1376907862775\index
[junit4] 2> 76368 T113 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-61-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@10a5132e
[junit4] 2> 76368 T113 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-61-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 76369 T113 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-61-thread-1]: 0 msec to checkpoint
[junit4] 2> 76369 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: init: create=true
[junit4] 2> 76369 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695)
[junit4] 2> index=
[junit4] 2> version=5.0-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_50
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=CREATE
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene42
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@1471f077
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 76370 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: now flush at close waitForMerges=true
[junit4] 2> 76370 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 76371 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: index before flush
[junit4] 2> 76371 T113 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-61-thread-1]: coreLoadExecutor-61-thread-1 startFullFlush
[junit4] 2> 76371 T113 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-61-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 76371 T113 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-61-thread-1]: coreLoadExecutor-61-thread-1 finishFullFlush success=true
[junit4] 2> 76371 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: apply all deletes during flush
[junit4] 2> 76371 T113 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-61-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@4d7bdf02 minGen=9223372036854775807 packetCount=0
[junit4] 2> 76372 T113 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-61-thread-1]: now merge
[junit4] 2> 76372 T113 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-61-thread-1]: index:
[junit4] 2> 76372 T113 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-61-thread-1]: no more merges pending; now return
[junit4] 2> 76372 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: waitForMerges
[junit4] 2> 76372 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: waitForMerges done
[junit4] 2> 76372 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: now call final commit()
[junit4] 2> 76372 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: commit: start
[junit4] 2> 76372 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: commit: enter lock
[junit4] 2> 76372 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: commit: now prepare
[junit4] 2> 76373 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: prepareCommit: flush
[junit4] 2> 76373 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: index before flush
[junit4] 2> 76373 T113 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-61-thread-1]: coreLoadExecutor-61-thread-1 startFullFlush
[junit4] 2> 76373 T113 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-61-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 76373 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: apply all deletes during flush
[junit4] 2> 76373 T113 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-61-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@4d7bdf02 minGen=9223372036854775807 packetCount=0
[junit4] 2> 76373 T113 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-61-thread-1]: coreLoadExecutor-61-thread-1 finishFullFlush success=true
[junit4] 2> 76373 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: startCommit(): start
[junit4] 2> 76374 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: startCommit index= changeCount=1
[junit4] 2> 76374 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: done all syncs: []
[junit4] 2> 76374 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: commit: pendingCommit != null
[junit4] 2> 76374 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: commit: wrote segments file "segments_1"
[junit4] 2> 76375 T113 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-61-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 76375 T113 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695),segFN=segments_1,generation=1}
[junit4] 2> 76375 T113 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 76376 T113 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-61-thread-1]: 0 msec to checkpoint
[junit4] 2> 76376 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: commit: done
[junit4] 2> 76376 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: at close:
[junit4] 2> 76378 T113 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 76379 T113 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
[junit4] 2> 76379 T113 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
[junit4] 2> 76379 T113 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
[junit4] 2> 76379 T113 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
[junit4] 2> 76381 T113 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 76382 T113 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 76382 T113 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
[junit4] 2> 76383 T113 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 76388 T113 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
[junit4] 2> 76389 T113 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 76389 T113 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.JsonUpdateRequestHandler
[junit4] 2> 76389 T113 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.CSVRequestHandler
[junit4] 2> 76389 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
[junit4] 2> 76390 T113 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
[junit4] 2> 76391 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[junit4] 2> 76391 T113 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
[junit4] 2> 76391 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[junit4] 2> 76391 T113 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
[junit4] 2> 76391 T113 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 76392 T113 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 76392 T113 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 76392 T113 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 76392 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 76393 T113 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
[junit4] 2> 76393 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 76393 T113 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
[junit4] 2> 76393 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: org.apache.solr.handler.js.JavaScriptRequestHandler
[junit4] 2> 76393 T113 oasc.RequestHandlers.initHandlersFromConfig created /js: org.apache.solr.handler.js.JavaScriptRequestHandler
[junit4] 2> 76393 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 76393 T113 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
[junit4] 2> 76393 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 76394 T113 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
[junit4] 2> 76401 T113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 76402 T113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 76404 T113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 76407 T113 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 76407 T113 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 76408 T113 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-61-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@10a5132e
[junit4] 2> 76409 T113 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-61-thread-1]: init: load commit "segments_1"
[junit4] 2> 76409 T113 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695),segFN=segments_1,generation=1}
[junit4] 2> 76409 T113 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 76409 T113 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-61-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 76410 T113 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-61-thread-1]: 0 msec to checkpoint
[junit4] 2> 76410 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: init: create=false
[junit4] 2> 76410 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695)
[junit4] 2> index=
[junit4] 2> version=5.0-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_50
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=APPEND
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene42
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@5c4eb228
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 76410 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: flush at getReader
[junit4] 2> 76410 T113 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-61-thread-1]: coreLoadExecutor-61-thread-1 startFullFlush
[junit4] 2> 76411 T113 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-61-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 76411 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: apply all deletes during flush
[junit4] 2> 76411 T113 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-61-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=9223372036854775807 packetCount=0
[junit4] 2> 76411 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 76411 T113 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-61-thread-1]: coreLoadExecutor-61-thread-1 finishFullFlush success=true
[junit4] 2> 76411 T113 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-61-thread-1]: getReader took 1 msec
[junit4] 2> 76411 T113 oass.SolrIndexSearcher.<init> Opening Searcher@36ecc179 main
[junit4] 2> 76411 T113 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 76412 T113 oass.DirectSolrSpellChecker.init init: {name=default,field=text,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 76413 T113 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
[junit4] 2> 76413 T113 oashc.QueryElevationComponent.inform Loading QueryElevation from: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\solr\collection1\conf\elevate.xml
[junit4] 2> 76437 T113 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 76440 T114 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@36ecc179 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> ASYNC NEW_CORE C19 name=collection1 org.apache.solr.core.SolrCore@6eb69c56
[junit4] 2> 76442 T114 C19 oasc.SolrCore.execute [collection1] webapp=null path=null params={event=firstSearcher&q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false} hits=0 status=0 QTime=2
[junit4] 2> 76442 T114 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 76442 T114 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 76442 T114 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 76443 T114 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36ecc179 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 76445 T113 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 76447 T103 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0
[junit4] 2> 76447 T103 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 76447 T103 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#52764
[junit4] 2> 76458 T103 oas.SolrTestCaseJ4.setUp ###Starting testErrorHandling
[junit4] 2> 76599 T103 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 76881 T110 C19 oasc.SolrException.log Ignoring exception matching ignore_exception
[junit4] 2> 76881 T110 C19 oasc.SolrCore.execute [collection1] webapp=/solr path=/analysis/field params={analysis.fieldtype=int&wt=javabin&qt=/analysis/field&analysis.fieldvalue=ignore_exception&version=2} status=400 QTime=1
[junit4] 2> 76899 T111 C19 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {} 0 1
[junit4] 2> 76899 T111 C19 oasc.SolrException.log Ignoring exception matching ignore_exception
[junit4] 2> 76905 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run starting runner: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@5eb56d72
[junit4] 2> 76912 T112 C19 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {} 0 0
[junit4] 2> 76912 T112 C19 oasc.SolrException.log ERROR org.apache.solr.common.SolrException: Document contains multiple values for uniqueKey field: id=[DOCID, DOCID2]
[junit4] 2> at org.apache.solr.update.AddUpdateCommand.getIndexedId(AddUpdateCommand.java:97)
[junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.versionAdd(DistributedUpdateProcessor.java:569)
[junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.processAdd(DistributedUpdateProcessor.java:435)
[junit4] 2> at org.apache.solr.update.processor.LogUpdateProcessor.processAdd(LogUpdateProcessorFactory.java:100)
[junit4] 2> at org.apache.solr.handler.loader.JavabinLoader$1.update(JavabinLoader.java:86)
[junit4] 2> at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec$1.readOuterMostDocIterator(JavaBinUpdateRequestCodec.java:143)
[junit4] 2> at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec$1.readIterator(JavaBinUpdateRequestCodec.java:123)
[junit4] 2> at org.apache.solr.common.util.JavaBinCodec.readVal(JavaBinCodec.java:222)
[junit4] 2> at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec$1.readNamedList(JavaBinUpdateRequestCodec.java:108)
[junit4] 2> at org.apache.solr.common.util.JavaBinCodec.readVal(JavaBinCodec.java:187)
[junit4] 2> at org.apache.solr.common.util.JavaBinCodec.unmarshal(JavaBinCodec.java:113)
[junit4] 2> at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec.unmarshal(JavaBinUpdateRequestCodec.java:150)
[junit4] 2> at org.apache.solr.handler.loader.JavabinLoader.parseAndLoadDocs(JavabinLoader.java:96)
[junit4] 2> at org.apache.solr.handler.loader.JavabinLoader.load(JavabinLoader.java:55)
[junit4] 2> at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:92)
[junit4] 2> at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:74)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
[junit4] 2> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1850)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:703)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:406)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:195)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:135)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
[junit4] 2> at org.eclipse.jetty.server.handler.GzipHandler.handle(GzipHandler.java:301)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1077)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:384)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1009)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:368)
[junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:489)
[junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:953)
[junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:1014)
[junit4] 2> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:953)
[junit4] 2> at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
[junit4] 2> at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
[junit4] 2> at org.eclipse.jetty.io.nio.SslConnection.handle(SslConnection.java:196)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2>
[junit4] 2> 77155 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run Status for: DOCID is 400
[junit4] 2> 77157 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run finished: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@5eb56d72
[junit4] 2> 77158 T103 oas.SolrTestCaseJ4.tearDown ###Ending testErrorHandling
[junit4] 2> 77172 T103 oas.SolrTestCaseJ4.setUp ###Starting testSetNullUpdates
[junit4] 2> 77226 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run starting runner: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@507298d4
[junit4] 2> 77477 T109 C19 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[testSetNullUpdates (1443792541153492992)]} 0 246
[junit4] 2> 77477 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run Status for: testSetNullUpdates is 200
[junit4] 2> 77477 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run finished: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@507298d4
[junit4] 2> 77481 T110 C19 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 77483 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: commit: start
[junit4] 2> 77483 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: commit: enter lock
[junit4] 2> 77483 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: commit: now prepare
[junit4] 2> 77483 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: prepareCommit: flush
[junit4] 2> 77484 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: index before flush
[junit4] 2> 77484 T110 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-110]: qtp593250988-110 startFullFlush
[junit4] 2> 77484 T110 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-110]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 77484 T110 C19 oasu.LoggingInfoStream.message [DWFC][qtp593250988-110]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_0, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 1 ]]
[junit4] 2> 77485 T110 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-110]: flush postings as segment _0 numDocs=1
[junit4] 2> 77487 T110 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-110]: new segment has 0 deleted docs
[junit4] 2> 77488 T110 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-110]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 77488 T110 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-110]: flushedFiles=[_0.fnm, _0_Lucene41_0.doc, _0.fdx, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt]
[junit4] 2> 77489 T110 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-110]: flushed codec=Lucene42
[junit4] 2> 77489 T110 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-110]: flushed: segment=_0 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,154.819
[junit4] 2> 77490 T110 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-110]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 77492 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: publishFlushedSegment
[junit4] 2> 77492 T110 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-110]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=2 packetCount=1 totBytesUsed=1024
[junit4] 2> 77492 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: publish sets newSegment delGen=3 seg=_0(5.0):C1
[junit4] 2> 77493 T110 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-110]: now checkpoint "_0(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 77493 T110 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-110]: 0 msec to checkpoint
[junit4] 2> 77493 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: apply all deletes during flush
[junit4] 2> 77493 T110 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-110]: applyDeletes: infos=[_0(5.0):C1] packetCount=1
[junit4] 2> 77493 T110 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-110]: applyDeletes took 0 msec
[junit4] 2> 77493 T110 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-110]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=4 packetCount=1
[junit4] 2> 77494 T110 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-110]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 77495 T110 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-110]: qtp593250988-110 finishFullFlush success=true
[junit4] 2> 77495 T110 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-110]: findMerges: 1 segments
[junit4] 2> 77495 T110 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-110]: seg=_0(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 77495 T110 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-110]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 77496 T110 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-110]: now merge
[junit4] 2> 77496 T110 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-110]: index: _0(5.0):C1
[junit4] 2> 77496 T110 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-110]: no more merges pending; now return
[junit4] 2> 77496 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: startCommit(): start
[junit4] 2> 77496 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: startCommit index=_0(5.0):C1 changeCount=3
[junit4] 2> 77497 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: done all syncs: [_0.fnm, _0_Lucene41_0.doc, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4] 2> 77497 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: commit: pendingCommit != null
[junit4] 2> 77497 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: commit: wrote segments file "segments_2"
[junit4] 2> 77497 T110 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-110]: now checkpoint "_0(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 77497 T110 C19 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695),segFN=segments_2,generation=2}
[junit4] 2> 77498 T110 C19 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 77499 T110 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-110]: deleteCommits: now decRef commit "segments_1"
[junit4] 2> 77499 T110 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-110]: delete "segments_1"
[junit4] 2> 77499 T110 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-110]: 2 msec to checkpoint
[junit4] 2> 77499 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: commit: done
[junit4] 2> 77500 T110 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-110]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 77500 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 77501 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: flush at getReader
[junit4] 2> 77501 T110 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-110]: qtp593250988-110 startFullFlush
[junit4] 2> 77501 T110 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-110]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 77501 T110 C19 oasu.LoggingInfoStream.message [DWFC][qtp593250988-110]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 2 ]]
[junit4] 2> 77502 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: apply all deletes during flush
[junit4] 2> 77502 T110 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-110]: applyDeletes: no deletes; skipping
[junit4] 2> 77502 T110 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-110]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=4 packetCount=0
[junit4] 2> 77503 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)
[junit4] 2> 77504 T110 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-110]: qtp593250988-110 finishFullFlush success=true
[junit4] 2> 77504 T110 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-110]: getReader took 3 msec
[junit4] 2> 77504 T110 C19 oass.SolrIndexSearcher.<init> Opening Searcher@3e9bcad6 main
[junit4] 2> 77505 T110 C19 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 77505 T114 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3e9bcad6 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4] 2> 77505 T114 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 77506 T114 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3e9bcad6 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4] 2> 77507 T110 C19 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 26
[junit4] 2> 77606 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run starting runner: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@544d0602
[junit4] 2> 77853 T112 C19 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[testSetNullUpdates (1443792541549854720)]} 0 244
[junit4] 2> 77854 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run Status for: testSetNullUpdates is 200
[junit4] 2> 77855 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run finished: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@544d0602
[junit4] 2> 77860 T107 C19 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 77861 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: commit: start
[junit4] 2> 77861 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: commit: enter lock
[junit4] 2> 77861 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: commit: now prepare
[junit4] 2> 77862 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: prepareCommit: flush
[junit4] 2> 77862 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: index before flush _0(5.0):C1
[junit4] 2> 77863 T107 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-107]: qtp593250988-107 startFullFlush
[junit4] 2> 77863 T107 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-107]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 77863 T107 C19 oasu.LoggingInfoStream.message [DWFC][qtp593250988-107]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_1, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 3 ]]
[junit4] 2> 77864 T107 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-107]: flush postings as segment _1 numDocs=1
[junit4] 2> 77865 T107 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-107]: new segment has 0 deleted docs
[junit4] 2> 77866 T107 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-107]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 77866 T107 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-107]: flushedFiles=[_1.fdx, _1_Lucene41_0.doc, _1.fdt, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1.fnm]
[junit4] 2> 77867 T107 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-107]: flushed codec=Lucene42
[junit4] 2> 77867 T107 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-107]: flushed: segment=_1 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,394.383
[junit4] 2> 77867 T107 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-107]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 77868 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: publishFlushedSegment
[junit4] 2> 77868 T107 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-107]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=6 packetCount=1 totBytesUsed=1024
[junit4] 2> 77868 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: publish sets newSegment delGen=7 seg=_1(5.0):C1
[junit4] 2> 77869 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: now checkpoint "_0(5.0):C1 _1(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 77869 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: 0 msec to checkpoint
[junit4] 2> 77869 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: apply all deletes during flush
[junit4] 2> 77869 T107 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-107]: applyDeletes: infos=[_0(5.0):C1, _1(5.0):C1] packetCount=1
[junit4] 2> 77870 T107 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-107]: seg=_0(5.0):C1 segGen=4 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=1 100% deleted
[junit4] 2> 77871 T107 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-107]: applyDeletes took 2 msec
[junit4] 2> 77871 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: now checkpoint "_0(5.0):C1/1 _1(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 77872 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: 0 msec to checkpoint
[junit4] 2> 77872 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: drop 100% deleted segments: _0(5.0):C1/1
[junit4] 2> 77872 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 77873 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: 0 msec to checkpoint
[junit4] 2> 77873 T107 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-107]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=8 packetCount=1
[junit4] 2> 77873 T107 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-107]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 77873 T107 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-107]: qtp593250988-107 finishFullFlush success=true
[junit4] 2> 77873 T107 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-107]: findMerges: 1 segments
[junit4] 2> 77874 T107 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-107]: seg=_1(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 77874 T107 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-107]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 77875 T107 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-107]: now merge
[junit4] 2> 77875 T107 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-107]: index: _1(5.0):C1
[junit4] 2> 77875 T107 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-107]: no more merges pending; now return
[junit4] 2> 77875 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: startCommit(): start
[junit4] 2> 77875 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: startCommit index=_1(5.0):C1 changeCount=8
[junit4] 2> 77875 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: done all syncs: [_1.fdx, _1_Lucene41_0.doc, _1.fdt, _1.si, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1.fnm]
[junit4] 2> 77875 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: commit: pendingCommit != null
[junit4] 2> 77875 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: commit: wrote segments file "segments_3"
[junit4] 2> 77876 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 77876 T107 C19 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695),segFN=segments_3,generation=3}
[junit4] 2> 77876 T107 C19 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 77876 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: deleteCommits: now decRef commit "segments_2"
[junit4] 2> 77877 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: delete "_0.fnm"
[junit4] 2> 77877 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: delete "_0_Lucene41_0.doc"
[junit4] 2> 77877 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: unable to remove file "_0_Lucene41_0.doc": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.doc" is still open: cannot delete; Will re-try later.
[junit4] 2> 77878 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: delete "segments_2"
[junit4] 2> 77879 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: delete "_0.fdx"
[junit4] 2> 77879 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: delete "_0.si"
[junit4] 2> 77880 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: delete "_0_Lucene41_0.tim"
[junit4] 2> 77880 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: unable to remove file "_0_Lucene41_0.tim": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.tim" is still open: cannot delete; Will re-try later.
[junit4] 2> 77880 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: delete "_0.fdt"
[junit4] 2> 77881 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: unable to remove file "_0.fdt": java.io.IOException: MockDirectoryWrapper: file "_0.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 77881 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: delete "_0_Lucene41_0.tip"
[junit4] 2> 77881 T107 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-107]: 5 msec to checkpoint
[junit4] 2> 77882 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: commit: done
[junit4] 2> 77882 T107 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-107]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 77883 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 77883 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: flush at getReader
[junit4] 2> 77883 T107 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-107]: qtp593250988-107 startFullFlush
[junit4] 2> 77884 T107 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-107]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 77884 T107 C19 oasu.LoggingInfoStream.message [DWFC][qtp593250988-107]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 4 ]]
[junit4] 2> 77885 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: apply all deletes during flush
[junit4] 2> 77885 T107 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-107]: applyDeletes: no deletes; skipping
[junit4] 2> 77886 T107 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-107]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=8 packetCount=0
[junit4] 2> 77887 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: return reader version=7 reader=StandardDirectoryReader(segments_3:7:nrt _1(5.0):C1)
[junit4] 2> 77888 T107 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-107]: qtp593250988-107 finishFullFlush success=true
[junit4] 2> 77888 T107 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-107]: getReader took 5 msec
[junit4] 2> 77888 T107 C19 oass.SolrIndexSearcher.<init> Opening Searcher@30497bf main
[junit4] 2> 77890 T107 C19 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 77890 T114 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@30497bf main{StandardDirectoryReader(segments_3:7:nrt _1(5.0):C1)}
[junit4] 2> 77891 T114 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 77893 T114 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@30497bf main{StandardDirectoryReader(segments_3:7:nrt _1(5.0):C1)}
[junit4] 2> 77893 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete pending file _0_Lucene41_0.doc
[junit4] 2> 77893 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete "_0_Lucene41_0.doc"
[junit4] 2> 77893 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete pending file _0_Lucene41_0.tim
[junit4] 2> 77893 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete "_0_Lucene41_0.tim"
[junit4] 2> 77894 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete pending file _0.fdt
[junit4] 2> 77894 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete "_0.fdt"
[junit4] 2> 77895 T107 C19 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 35
[junit4] 2> 77915 T108 C19 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=id:testSetNullUpdates&wt=javabin&version=2} hits=1 status=0 QTime=5
[junit4] 2> 77919 T103 oas.SolrTestCaseJ4.tearDown ###Ending testSetNullUpdates
[junit4] 2> 77936 T103 oas.SolrTestCaseJ4.setUp ###Starting testSetNullUpdateOrder
[junit4] 2> 77942 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run starting runner: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@114f92ef
[junit4] 2> 78192 T110 C19 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[testSetNullUpdateOrder (1443792541903224832)]} 0 246
[junit4] 2> 78193 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run Status for: testSetNullUpdateOrder is 200
[junit4] 2> 78194 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run finished: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@114f92ef
[junit4] 2> 78198 T112 C19 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 78198 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: commit: start
[junit4] 2> 78199 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: commit: enter lock
[junit4] 2> 78199 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: commit: now prepare
[junit4] 2> 78199 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: prepareCommit: flush
[junit4] 2> 78200 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: index before flush _1(5.0):C1
[junit4] 2> 78200 T112 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-112]: qtp593250988-112 startFullFlush
[junit4] 2> 78200 T112 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-112]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 78201 T112 C19 oasu.LoggingInfoStream.message [DWFC][qtp593250988-112]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_2, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 5 ]]
[junit4] 2> 78201 T112 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-112]: flush postings as segment _2 numDocs=1
[junit4] 2> 78204 T112 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-112]: new segment has 0 deleted docs
[junit4] 2> 78204 T112 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-112]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 78204 T112 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-112]: flushedFiles=[_2_Lucene41_0.tim, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fdx, _2.fnm]
[junit4] 2> 78205 T112 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-112]: flushed codec=Lucene42
[junit4] 2> 78205 T112 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-112]: flushed: segment=_2 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,144.734
[junit4] 2> 78205 T112 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-112]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 78206 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: publishFlushedSegment
[junit4] 2> 78206 T112 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-112]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=10 packetCount=1 totBytesUsed=1024
[junit4] 2> 78206 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: publish sets newSegment delGen=11 seg=_2(5.0):C1
[junit4] 2> 78207 T112 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-112]: now checkpoint "_1(5.0):C1 _2(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 78207 T112 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-112]: 0 msec to checkpoint
[junit4] 2> 78207 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: apply all deletes during flush
[junit4] 2> 78207 T112 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-112]: applyDeletes: infos=[_1(5.0):C1, _2(5.0):C1] packetCount=1
[junit4] 2> 78208 T112 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-112]: seg=_1(5.0):C1 segGen=8 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=0
[junit4] 2> 78208 T112 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-112]: applyDeletes took 1 msec
[junit4] 2> 78209 T112 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-112]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=12 packetCount=1
[junit4] 2> 78209 T112 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-112]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 78210 T112 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-112]: qtp593250988-112 finishFullFlush success=true
[junit4] 2> 78210 T112 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-112]: findMerges: 2 segments
[junit4] 2> 78211 T112 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-112]: seg=_2(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 78211 T112 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-112]: seg=_1(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 78212 T112 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-112]: allowedSegmentCount=1 vs count=2 (eligible count=2) tooBigCount=0
[junit4] 2> 78212 T112 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-112]: now merge
[junit4] 2> 78212 T112 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-112]: index: _1(5.0):C1 _2(5.0):C1
[junit4] 2> 78213 T112 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-112]: no more merges pending; now return
[junit4] 2> 78213 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: startCommit(): start
[junit4] 2> 78214 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: startCommit index=_1(5.0):C1 _2(5.0):C1 changeCount=11
[junit4] 2> 78214 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: done all syncs: [_2.si, _1_Lucene41_0.doc, _2_Lucene41_0.tim, _1_Lucene41_0.tim, _2.fdt, _1_Lucene41_0.tip, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fdx, _1.fnm, _2.fnm, _1.fdx, _1.fdt, _1.si]
[junit4] 2> 78214 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: commit: pendingCommit != null
[junit4] 2> 78214 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: commit: wrote segments file "segments_4"
[junit4] 2> 78214 T112 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-112]: now checkpoint "_1(5.0):C1 _2(5.0):C1" [2 segments ; isCommit = true]
[junit4] 2> 78215 T112 C19 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695),segFN=segments_4,generation=4}
[junit4] 2> 78215 T112 C19 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 78216 T112 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-112]: deleteCommits: now decRef commit "segments_3"
[junit4] 2> 78217 T112 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-112]: delete "segments_3"
[junit4] 2> 78217 T112 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-112]: 2 msec to checkpoint
[junit4] 2> 78218 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: commit: done
[junit4] 2> 78218 T112 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-112]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 78218 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 78219 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: flush at getReader
[junit4] 2> 78219 T112 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-112]: qtp593250988-112 startFullFlush
[junit4] 2> 78219 T112 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-112]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 78220 T112 C19 oasu.LoggingInfoStream.message [DWFC][qtp593250988-112]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 6 ]]
[junit4] 2> 78220 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: apply all deletes during flush
[junit4] 2> 78221 T112 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-112]: applyDeletes: no deletes; skipping
[junit4] 2> 78221 T112 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-112]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=12 packetCount=0
[junit4] 2> 78222 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: return reader version=9 reader=StandardDirectoryReader(segments_4:9:nrt _1(5.0):C1 _2(5.0):C1)
[junit4] 2> 78223 T112 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-112]: qtp593250988-112 finishFullFlush success=true
[junit4] 2> 78223 T112 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-112]: getReader took 4 msec
[junit4] 2> 78223 T112 C19 oass.SolrIndexSearcher.<init> Opening Searcher@2cd59ecc main
[junit4] 2> 78224 T112 C19 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 78225 T114 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2cd59ecc main{StandardDirectoryReader(segments_4:9:nrt _1(5.0):C1 _2(5.0):C1)}
[junit4] 2> 78225 T114 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 78227 T114 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2cd59ecc main{StandardDirectoryReader(segments_4:9:nrt _1(5.0):C1 _2(5.0):C1)}
[junit4] 2> 78228 T112 C19 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 31
[junit4] 2> 78231 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run starting runner: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@6464a349
[junit4] 2> 78477 T107 C19 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[testSetNullUpdateOrder (1443792542204166144)]} 0 244
[junit4] 2> 78478 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run Status for: testSetNullUpdateOrder is 200
[junit4] 2> 78479 T116 oascsi.ConcurrentUpdateSolrServer$Runner.run finished: org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner@6464a349
[junit4] 2> 78483 T108 C19 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 78484 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: commit: start
[junit4] 2> 78484 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: commit: enter lock
[junit4] 2> 78484 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: commit: now prepare
[junit4] 2> 78485 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: prepareCommit: flush
[junit4] 2> 78485 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: index before flush _1(5.0):C1 _2(5.0):C1
[junit4] 2> 78485 T108 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-108]: qtp593250988-108 startFullFlush
[junit4] 2> 78485 T108 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-108]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 78485 T108 C19 oasu.LoggingInfoStream.message [DWFC][qtp593250988-108]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_3, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 7 ]]
[junit4] 2> 78487 T108 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-108]: flush postings as segment _3 numDocs=1
[junit4] 2> 78487 T108 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-108]: new segment has 0 deleted docs
[junit4] 2> 78487 T108 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-108]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 78488 T108 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-108]: flushedFiles=[_3.fdx, _3_Lucene41_0.doc, _3_Lucene41_0.tip, _3.fnm, _3_Lucene41_0.tim, _3.fdt]
[junit4] 2> 78488 T108 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-108]: flushed codec=Lucene42
[junit4] 2> 78488 T108 C19 oasu.LoggingInfoStream.message [DWPT][qtp593250988-108]: flushed: segment=_3 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,376.084
[junit4] 2> 78489 T108 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-108]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 78489 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: publishFlushedSegment
[junit4] 2> 78490 T108 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-108]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=14 packetCount=1 totBytesUsed=1024
[junit4] 2> 78490 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: publish sets newSegment delGen=15 seg=_3(5.0):C1
[junit4] 2> 78490 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: now checkpoint "_1(5.0):C1 _2(5.0):C1 _3(5.0):C1" [3 segments ; isCommit = false]
[junit4] 2> 78491 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: 0 msec to checkpoint
[junit4] 2> 78492 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: apply all deletes during flush
[junit4] 2> 78492 T108 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-108]: applyDeletes: infos=[_1(5.0):C1, _2(5.0):C1, _3(5.0):C1] packetCount=1
[junit4] 2> 78492 T108 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-108]: seg=_2(5.0):C1 segGen=12 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=1 100% deleted
[junit4] 2> 78492 T108 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-108]: seg=_1(5.0):C1 segGen=12 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=0
[junit4] 2> 78492 T108 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-108]: applyDeletes took 0 msec
[junit4] 2> 78492 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: now checkpoint "_1(5.0):C1 _2(5.0):C1/1 _3(5.0):C1" [3 segments ; isCommit = false]
[junit4] 2> 78492 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: 0 msec to checkpoint
[junit4] 2> 78493 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: drop 100% deleted segments: _2(5.0):C1/1
[junit4] 2> 78493 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: now checkpoint "_1(5.0):C1 _3(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 78493 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: 0 msec to checkpoint
[junit4] 2> 78494 T108 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-108]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=16 packetCount=1
[junit4] 2> 78494 T108 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-108]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 78494 T108 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-108]: qtp593250988-108 finishFullFlush success=true
[junit4] 2> 78494 T108 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-108]: findMerges: 2 segments
[junit4] 2> 78494 T108 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-108]: seg=_3(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 78495 T108 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-108]: seg=_1(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 78495 T108 C19 oasu.LoggingInfoStream.message [TMP][qtp593250988-108]: allowedSegmentCount=1 vs count=2 (eligible count=2) tooBigCount=0
[junit4] 2> 78495 T108 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-108]: now merge
[junit4] 2> 78495 T108 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-108]: index: _1(5.0):C1 _3(5.0):C1
[junit4] 2> 78496 T108 C19 oasu.LoggingInfoStream.message [CMS][qtp593250988-108]: no more merges pending; now return
[junit4] 2> 78496 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: startCommit(): start
[junit4] 2> 78496 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: startCommit index=_1(5.0):C1 _3(5.0):C1 changeCount=16
[junit4] 2> 78497 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: done all syncs: [_1_Lucene41_0.doc, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _3.fdt, _3.fnm, _1.fnm, _3.fdx, _1.fdx, _3_Lucene41_0.doc, _1.fdt, _3_Lucene41_0.tip, _1.si, _3.si, _3_Lucene41_0.tim]
[junit4] 2> 78497 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: commit: pendingCommit != null
[junit4] 2> 78497 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: commit: wrote segments file "segments_5"
[junit4] 2> 78498 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: now checkpoint "_1(5.0):C1 _3(5.0):C1" [2 segments ; isCommit = true]
[junit4] 2> 78498 T108 C19 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@571c3407 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6767c695),segFN=segments_5,generation=5}
[junit4] 2> 78498 T108 C19 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 78498 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: deleteCommits: now decRef commit "segments_4"
[junit4] 2> 78499 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: delete "_2.si"
[junit4] 2> 78499 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: delete "_2_Lucene41_0.tim"
[junit4] 2> 78499 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: unable to remove file "_2_Lucene41_0.tim": java.io.IOException: MockDirectoryWrapper: file "_2_Lucene41_0.tim" is still open: cannot delete; Will re-try later.
[junit4] 2> 78500 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: delete "_2.fdt"
[junit4] 2> 78500 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: unable to remove file "_2.fdt": java.io.IOException: MockDirectoryWrapper: file "_2.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 78500 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: delete "_2_Lucene41_0.doc"
[junit4] 2> 78500 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: unable to remove file "_2_Lucene41_0.doc": java.io.IOException: MockDirectoryWrapper: file "_2_Lucene41_0.doc" is still open: cannot delete; Will re-try later.
[junit4] 2> 78500 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: delete "_2_Lucene41_0.tip"
[junit4] 2> 78500 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: delete "_2.fdx"
[junit4] 2> 78500 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: delete "_2.fnm"
[junit4] 2> 78500 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: delete "segments_4"
[junit4] 2> 78502 T108 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-108]: 3 msec to checkpoint
[junit4] 2> 78502 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: commit: done
[junit4] 2> 78502 T108 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-108]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 78502 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 78502 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: flush at getReader
[junit4] 2> 78502 T108 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-108]: qtp593250988-108 startFullFlush
[junit4] 2> 78503 T108 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-108]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 78504 T108 C19 oasu.LoggingInfoStream.message [DWFC][qtp593250988-108]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 8 ]]
[junit4] 2> 78504 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: apply all deletes during flush
[junit4] 2> 78504 T108 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-108]: applyDeletes: no deletes; skipping
[junit4] 2> 78504 T108 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-108]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=16 packetCount=0
[junit4] 2> 78505 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: return reader version=13 reader=StandardDirectoryReader(segments_5:13:nrt _1(5.0):C1 _3(5.0):C1)
[junit4] 2> 78505 T108 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-108]: qtp593250988-108 finishFullFlush success=true
[junit4] 2> 78505 T108 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-108]: getReader took 3 msec
[junit4] 2> 78506 T108 C19 oass.SolrIndexSearcher.<init> Opening Searcher@4170390a main
[junit4] 2> 78506 T108 C19 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 78507 T114 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4170390a main{StandardDirectoryReader(segments_5:13:nrt _1(5.0):C1 _3(5.0):C1)}
[junit4] 2> 78507 T114 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 78508 T114 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4170390a main{StandardDirectoryReader(segments_5:13:nrt _1(5.0):C1 _3(5.0):C1)}
[junit4] 2> 78509 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete pending file _2_Lucene41_0.tim
[junit4] 2> 78510 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete "_2_Lucene41_0.tim"
[junit4] 2> 78510 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete pending file _2.fdt
[junit4] 2> 78510 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete "_2.fdt"
[junit4] 2> 78511 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete pending file _2_Lucene41_0.doc
[junit4] 2> 78511 T114 oasu.LoggingInfoStream.message [IFD][searcherExecutor-62-thread-1]: delete "_2_Lucene41_0.doc"
[junit4] 2> 78511 T108 C19 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 28
[junit4] 2> 78519 T109 C19 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=id:testSetNullUpdateOrder&wt=javabin&version=2} hits=1 status=0 QTime=1
[junit4] 2> 78525 T103 oas.SolrTestCaseJ4.tearDown ###Ending testSetNullUpdateOrder
[junit4] 2> 78533 T103 oas.SolrTestCaseJ4.setUp ###Starting testGetEmptyResults
[junit4] 2> 78539 T111 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-111]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 78539 T111 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-111]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 78539 T111 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-111]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 78540 T111 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-111]: flush at getReader
[junit4] 2> 78540 T111 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-111]: qtp593250988-111 startFullFlush
[junit4] 2> 78540 T111 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-111]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 78540 T111 C19 oasu.LoggingInfoStream.message [DWFC][qtp593250988-111]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 9 ]]
[junit4] 2> 78541 T111 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-111]: qtp593250988-111: flush naked frozen global deletes
[junit4] 2> 78542 T111 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-111]: push deletes 1 deleted queries bytesUsed=36 delGen=18 packetCount=1 totBytesUsed=36
[junit4] 2> 78542 T111 C19 oasu.LoggingInfoStream.message [DW][qtp593250988-111]: flush: push buffered deletes: 1 deleted queries bytesUsed=36
[junit4] 2> 78543 T111 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-111]: apply all deletes during flush
[junit4] 2> 78544 T111 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-111]: applyDeletes: infos=[_1(5.0):C1, _3(5.0):C1] packetCount=1
[junit4] 2> 78546 T111 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-111]: seg=_3(5.0):C1 segGen=16 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=1 100% deleted
[junit4] 2> 78549 T111 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-111]: seg=_1(5.0):C1 segGen=16 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=1 100% deleted
[junit4] 2> 78549 T111 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-111]: applyDeletes took 6 msec
[junit4] 2> 78550 T111 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-111]: now checkpoint "_1(5.0):C1/1 _3(5.0):C1/1" [2 segments ; isCommit = false]
[junit4] 2> 78550 T111 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-111]: 0 msec to checkpoint
[junit4] 2> 78551 T111 C19 oasu.LoggingInfoStream.message [IW][qtp593250988-111]: drop 100% deleted segments: _3(5.0):C1/1 _1(5.0):C1/1
[junit4] 2> 78551 T111 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-111]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 78552 T111 C19 oasu.LoggingInfoStream.message [IFD][qtp593250988-111]: 0 msec to checkpoint
[junit4] 2> 78552 T111 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-111]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=9223372036854775807 packetCount=1
[junit4] 2> 78552 T111 C19 oasu.LoggingInfoStream.message [BD][qtp593250988-111]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 78553 T111 C19 oasu.LoggingInfoStream.message [IW][qtp5932509
[...truncated too long message...]
rCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 294117 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: now flush at close waitForMerges=true
[junit4] 2> 294118 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: start flush: applyAllDeletes=true
[junit4] 2> 294118 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: index before flush _1k(5.0):C10
[junit4] 2> 294119 T103 C21 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker startFullFlush
[junit4] 2> 294119 T103 C21 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 294119 T103 C21 oasu.LoggingInfoStream.message [DWFC][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 155 ]]
[junit4] 2> 294120 T103 C21 oasu.LoggingInfoStream.message [DWFC][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 155 ]]
[junit4] 2> 294120 T103 C21 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker finishFullFlush success=true
[junit4] 2> 294120 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: apply all deletes during flush
[junit4] 2> 294120 T103 C21 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 294120 T103 C21 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=286 packetCount=0
[junit4] 2> 294121 T103 C21 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: now merge
[junit4] 2> 294121 T103 C21 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: index: _1k(5.0):C10
[junit4] 2> 294122 T103 C21 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: no more merges pending; now return
[junit4] 2> 294122 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: waitForMerges
[junit4] 2> 294122 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: waitForMerges done
[junit4] 2> 294123 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: now call final commit()
[junit4] 2> 294123 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: commit: start
[junit4] 2> 294123 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: commit: enter lock
[junit4] 2> 294123 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: commit: now prepare
[junit4] 2> 294123 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: prepareCommit: flush
[junit4] 2> 294124 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: index before flush _1k(5.0):C10
[junit4] 2> 294125 T103 C21 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker startFullFlush
[junit4] 2> 294125 T103 C21 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 294125 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: apply all deletes during flush
[junit4] 2> 294125 T103 C21 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 294126 T103 C21 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@657b163a minGen=286 packetCount=0
[junit4] 2> 294126 T103 C21 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker finishFullFlush success=true
[junit4] 2> 294126 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: startCommit(): start
[junit4] 2> 294126 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: skip startCommit(): no changes pending
[junit4] 2> 294127 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: commit: pendingCommit == null; skip
[junit4] 2> 294128 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: commit: done
[junit4] 2> 294128 T103 C21 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleStreamingBinaryTest-seed#[2358F4A026812AF9]-worker]: at close: _1k(5.0):C10
[junit4] 2> 294133 T103 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 294133 T103 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 294133 T103 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleStreamingBinaryTest-1376907862775\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleStreamingBinaryTest-1376907862775\;done=false>>]
[junit4] 2> 294133 T103 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleStreamingBinaryTest-1376907862775\
[junit4] 2> 294133 T103 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleStreamingBinaryTest-1376907862775\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleStreamingBinaryTest-1376907862775\index;done=false>>]
[junit4] 2> 294134 T103 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\solrtest-SolrExampleStreamingBinaryTest-1376907862775\index
[junit4] 2> 294134 T103 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 294188 T103 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=ar_MA, timezone=Australia/Adelaide
[junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=2,threads=9,free=12897576,total=217055232
[junit4] 2> NOTE: All tests run in this JVM: [TestSolrProperties, SolrExampleStreamingTest, FacetFieldTest, SolrExampleBinaryTest, TermsResponseTest, TestFastInputStream, MultiCoreEmbeddedTest, TestDocumentObjectBinder, NamedListTest, SolrExampleStreamingBinaryTest]
[junit4] Completed in 218.97s, 27 tests, 1 error <<< FAILURES!
[...truncated 119 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:389: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:369: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:194: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:450: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1230: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:873: There were test failures: 46 suites, 272 tests, 1 error, 1 ignored (1 assumption)
Total time: 73 minutes 29 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-ea-b102 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.8.0-ea-b102) -
Build # 3167 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3167/
Java: 32bit/jdk1.8.0-ea-b102 -server -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestStressReplication
Error Message:
timed out waiting for collection1 startAt time to exceed: Mon Aug 19 19:13:36 EEST 2013
Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Mon Aug 19 19:13:36 EEST 2013
at __randomizedtesting.SeedInfo.seed([25C16452897DD62A:FE6A64948C55BF99]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1513)
at org.apache.solr.handler.TestReplicationHandler.doTestStressReplication(TestReplicationHandler.java:817)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:491)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 9607 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> 598951 T1721 oas.SolrTestCaseJ4.setUp ###Starting doTestReplicateAfterStartupWithNoActivity
[junit4] 2> 598967 T1721 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 598971 T1721 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50028
[junit4] 2> 598972 T1721 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 598972 T1721 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 598972 T1721 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master
[junit4] 2> 598972 T1721 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\'
[junit4] 2> 599001 T1721 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\solr.xml
[junit4] 2> 599003 T1721 oasc.ConfigSolr.fromFile C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\solr.xml does not exist, using default configuration
[junit4] 2> 599024 T1721 oasc.CoreContainer.<init> New CoreContainer 21299004
[junit4] 2> 599024 T1721 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\]
[junit4] 2> 599025 T1721 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 599026 T1721 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 599026 T1721 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 599026 T1721 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 599026 T1721 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 599027 T1721 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 599027 T1721 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 599027 T1721 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 599027 T1721 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 599028 T1721 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 599043 T1733 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1
[junit4] 2> 599043 T1733 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\'
[junit4] 2> 599065 T1733 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 599077 T1733 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 599078 T1733 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 599081 T1733 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 599085 T1733 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 599086 T1733 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 599086 T1733 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\
[junit4] 2> 599086 T1733 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 599086 T1733 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\
[junit4] 2> 599086 T1733 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\index/
[junit4] 2> 599086 T1733 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\index' doesn't exist. Creating new index...
[junit4] 2> 599087 T1733 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\index
[junit4] 2> 599087 T1733 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.32509685421600876]
[junit4] 2> 599088 T1733 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@f8696c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@da3394; maxCacheMB=0.1044921875 maxMergeSizeMB=0.1318359375)),segFN=segments_1,generation=1}
[junit4] 2> 599088 T1733 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 599089 T1733 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 599089 T1733 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 599089 T1733 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 599090 T1733 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 599091 T1733 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 599091 T1733 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 599091 T1733 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 599096 T1733 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 599097 T1733 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 599098 T1733 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 599098 T1733 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=25, maxMergedSegmentMB=34.5927734375, floorSegmentMB=1.9775390625, forceMergeDeletesPctAllowed=11.71079264002832, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.32014162938628515
[junit4] 2> 599098 T1733 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@f8696c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@da3394; maxCacheMB=0.1044921875 maxMergeSizeMB=0.1318359375)),segFN=segments_1,generation=1}
[junit4] 2> 599099 T1733 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 599099 T1733 oass.SolrIndexSearcher.<init> Opening Searcher@b2580b main
[junit4] 2> 599099 T1733 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 599099 T1733 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 599100 T1733 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 599100 T1734 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b2580b main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 599100 T1721 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 599101 T1721 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 599101 T1721 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 599117 T1721 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 599122 T1721 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50031
[junit4] 2> 599123 T1721 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 599123 T1721 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 599123 T1721 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave
[junit4] 2> 599124 T1721 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\'
[junit4] 2> 599139 T1721 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\solr.xml
[junit4] 2> 599141 T1721 oasc.ConfigSolr.fromFile C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\solr.xml does not exist, using default configuration
[junit4] 2> 599152 T1721 oasc.CoreContainer.<init> New CoreContainer 8930170
[junit4] 2> 599153 T1721 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\]
[junit4] 2> 599153 T1721 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 599153 T1721 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 599154 T1721 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 599154 T1721 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 599154 T1721 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 599154 T1721 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 599155 T1721 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 599155 T1721 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 599155 T1721 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 599156 T1721 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 599163 T1745 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1
[junit4] 2> 599163 T1745 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\'
[junit4] 2> 599184 T1745 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 599197 T1745 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 599198 T1745 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 599201 T1745 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 599203 T1745 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 599203 T1745 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 599203 T1745 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\data\
[junit4] 2> 599203 T1745 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 599204 T1745 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\data\
[junit4] 2> 599204 T1745 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\data\index/
[junit4] 2> 599204 T1745 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\data\index' doesn't exist. Creating new index...
[junit4] 2> 599204 T1745 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\data\index
[junit4] 2> 599205 T1745 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.32509685421600876]
[junit4] 2> 599205 T1745 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@a16672 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1b8e831; maxCacheMB=0.1044921875 maxMergeSizeMB=0.1318359375)),segFN=segments_1,generation=1}
[junit4] 2> 599205 T1745 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 599207 T1745 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 599207 T1745 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 599207 T1745 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 599207 T1745 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 599207 T1745 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 599208 T1745 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 599208 T1745 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 599209 T1745 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 599211 T1745 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 599211 T1745 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 599211 T1745 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=25, maxMergedSegmentMB=34.5927734375, floorSegmentMB=1.9775390625, forceMergeDeletesPctAllowed=11.71079264002832, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.32014162938628515
[junit4] 2> 599212 T1745 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@a16672 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1b8e831; maxCacheMB=0.1044921875 maxMergeSizeMB=0.1318359375)),segFN=segments_1,generation=1}
[junit4] 2> 599212 T1745 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 599212 T1745 oass.SolrIndexSearcher.<init> Opening Searcher@16828d4 main
[junit4] 2> 599213 T1745 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 599213 T1745 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 599215 T1721 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 599215 T1721 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 599215 T1721 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 599219 T1746 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16828d4 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 599232 T1721 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=8930170
[junit4] 2> 599232 T1721 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5af1e3
[junit4] 2> 599233 T1721 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 599233 T1721 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 599233 T1721 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 599233 T1721 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 599235 T1721 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 599235 T1721 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 599235 T1721 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\data\;done=false>>]
[junit4] 2> 599235 T1721 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\data\
[junit4] 2> 599236 T1721 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\data\index;done=false>>]
[junit4] 2> 599236 T1721 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800248\slave\collection1\data\index
[junit4] 2> 599237 T1721 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> ASYNC NEW_CORE C1064 name=collection1 org.apache.solr.core.SolrCore@17299aa
[junit4] 2> 599292 T1731 C1064 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 599293 T1731 C1064 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:*} 0 2
[junit4] 2> 599296 T1724 C1064 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 599298 T1724 C1064 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@f8696c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@da3394; maxCacheMB=0.1044921875 maxMergeSizeMB=0.1318359375)),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@f8696c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@da3394; maxCacheMB=0.1044921875 maxMergeSizeMB=0.1318359375)),segFN=segments_2,generation=2}
[junit4] 2> 599299 T1724 C1064 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 599299 T1724 C1064 oass.SolrIndexSearcher.<init> Opening Searcher@1364952 main
[junit4] 2> 599300 T1724 C1064 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 599300 T1734 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1364952 main{StandardDirectoryReader(segments_2:2:nrt)}
[junit4] 2> 599300 T1724 C1064 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 4
[junit4] 2> 599315 T1721 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=21299004
[junit4] 2> 599315 T1721 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@17299aa
[junit4] 2> 599316 T1721 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4] 2> 599317 T1721 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 599317 T1721 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 599318 T1721 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 599319 T1721 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 599319 T1721 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 599319 T1721 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\;done=false>>]
[junit4] 2> 599319 T1721 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\
[junit4] 2> 599320 T1721 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\index;done=false>>]
[junit4] 2> 599320 T1721 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\index
[junit4] 2> 599320 T1721 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 599373 T1721 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 599377 T1721 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50035
[junit4] 2> 599378 T1721 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 599378 T1721 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 599379 T1721 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master
[junit4] 2> 599379 T1721 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\'
[junit4] 2> 599396 T1721 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\solr.xml
[junit4] 2> 599396 T1721 oasc.ConfigSolr.fromFile C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\solr.xml does not exist, using default configuration
[junit4] 2> 599416 T1721 oasc.CoreContainer.<init> New CoreContainer 19275136
[junit4] 2> 599416 T1721 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\]
[junit4] 2> 599417 T1721 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 599417 T1721 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 599417 T1721 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 599417 T1721 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 599418 T1721 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 599418 T1721 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 599418 T1721 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 599418 T1721 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 599419 T1721 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 599419 T1721 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 599427 T1758 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1
[junit4] 2> 599427 T1758 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\'
[junit4] 2> 599447 T1758 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 599459 T1758 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 599460 T1758 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 599463 T1758 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 599465 T1758 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 599465 T1758 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4] 2> 599494 T1758 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\
[junit4] 2> 599494 T1758 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 599495 T1758 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data
[junit4] 2> 599496 T1758 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\index/
[junit4] 2> 599497 T1758 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\index' doesn't exist. Creating new index...
[junit4] 2> 599497 T1758 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\index
[junit4] 2> 599498 T1758 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=93.962890625, floorSegmentMB=0.4638671875, forceMergeDeletesPctAllowed=3.1607997854547887, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 599504 T1758 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1dc70d9; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 599505 T1758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 599505 T1758 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 599506 T1758 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 599506 T1758 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 599506 T1758 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 599506 T1758 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 599507 T1758 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 599507 T1758 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 599514 T1758 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 599515 T1758 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 599516 T1758 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 599518 T1758 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=18, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.31559193767365407]
[junit4] 2> 599520 T1758 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928800095\master\collection1\data\index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1dc70d9; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 599520 T1758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 599520 T1758 oass.SolrIndexSearcher.<init> Opening Searcher@c618e3 main
[junit4] 2> 599520 T1758 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml
[junit4] 2> 599521 T1758 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 599521 T1758 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 599521 T1759 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c618e3 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 599522 T1721 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 599522 T1721 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 599522 T1721 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C1065 name=collection1 org.apache.solr.core.SolrCore@1fa2aaf
[junit4] 2> 599542 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0]} 0 10
[junit4] 2> 599547 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 1
[junit4] 2> 599549 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 0
[junit4] 2> 599551 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[3]} 0 0
[junit4] 2> 599552 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[4]} 0 0
[junit4] 2> 599555 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[5]} 0 0
[junit4] 2> 599558 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[6]} 0 0
[junit4] 2> 599561 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[7]} 0 0
[junit4] 2> 599565 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[8]} 0 0
[junit4] 2> 599568 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[9]} 0 0
[junit4] 2> 599571 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[10]} 0 0
[junit4] 2> 599574 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[11]} 0 0
[junit4] 2> 599577 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[12]} 0 0
[junit4] 2> 599579 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[13]} 0 0
[junit4] 2> 599581 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[14]} 0 0
[junit4] 2> 599584 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[15]} 0 0
[junit4] 2> 599587 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[16]} 0 0
[junit4] 2> 599591 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[17]} 0 0
[junit4] 2> 599593 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[18]} 0 0
[junit4] 2> 599596 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[19]} 0 0
[junit4] 2> 599599 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[20]} 0 0
[junit4] 2> 599601 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[21]} 0 0
[junit4] 2> 599603 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[22]} 0 0
[junit4] 2> 599605 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[23]} 0 0
[junit4] 2> 599607 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[24]} 0 0
[junit4] 2> 599609 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[25]} 0 0
[junit4] 2> 599611 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[26]} 0 0
[junit4] 2> 599612 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[27]} 0 0
[junit4] 2> 599621 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[28]} 0 0
[junit4] 2> 599624 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[29]} 0 0
[junit4] 2> 599626 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[30]} 0 0
[junit4] 2> 599628 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[31]} 0 0
[junit4] 2> 599630 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[32]} 0 0
[junit4] 2> 599632 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[33]} 0 0
[junit4] 2> 599634 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[34]} 0 0
[junit4] 2> 599636 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[35]} 0 0
[junit4] 2> 599638 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[36]} 0 0
[junit4] 2> 599640 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[37]} 0 0
[junit4] 2> 599641 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[38]} 0 0
[junit4] 2> 599643 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[39]} 0 0
[junit4] 2> 599645 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[40]} 0 0
[junit4] 2> 599648 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[41]} 0 0
[junit4] 2> 599650 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[42]} 0 0
[junit4] 2> 599652 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[43]} 0 0
[junit4] 2> 599654 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[44]} 0 0
[junit4] 2> 599656 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[45]} 0 0
[junit4] 2> 599658 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[46]} 0 0
[junit4] 2> 599661 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[47]} 0 0
[junit4] 2> 599664 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[48]} 0 0
[junit4] 2> 599667 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[49]} 0 0
[junit4] 2> 599669 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[50]} 0 0
[junit4] 2> 599674 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[51]} 0 0
[junit4] 2> 599677 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[52]} 0 0
[junit4] 2> 599680 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[53]} 0 0
[junit4] 2> 599683 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[54]} 0 0
[junit4] 2> 599685 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[55]} 0 0
[junit4] 2> 599688 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[56]} 0 0
[junit4] 2> 599691 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[57]} 0 0
[junit4] 2> 599694 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[58]} 0 0
[junit4] 2> 599697 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[59]} 0 0
[junit4] 2> 599699 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[60]} 0 0
[junit4] 2> 599701 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[61]} 0 0
[junit4] 2> 599703 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[62]} 0 0
[junit4] 2> 599722 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[63]} 0 0
[junit4] 2> 599725 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[64]} 0 0
[junit4] 2> 599727 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[65]} 0 0
[junit4] 2> 599729 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[66]} 0 0
[junit4] 2> 599731 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[67]} 0 0
[junit4] 2> 599735 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[68]} 0 1
[junit4] 2> 599742 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[69]} 0 5
[junit4] 2> 599746 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[70]} 0 0
[junit4] 2> 599750 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[71]} 0 0
[junit4] 2> 599754 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[72]} 0 0
[junit4] 2> 599756 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[73]} 0 0
[junit4] 2> 599758 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[74]} 0 0
[junit4] 2> 599763 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[75]} 0 3
[junit4] 2> 599765 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[76]} 0 0
[junit4] 2> 599768 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[77]} 0 0
[junit4] 2> 599771 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[78]} 0 0
[junit4] 2> 599774 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[79]} 0 0
[junit4] 2> 599776 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[80]} 0 0
[junit4] 2> 599778 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[81]} 0 0
[junit4] 2> 599785 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[82]} 0 5
[junit4] 2> 599787 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[83]} 0 0
[junit4] 2> 599790 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[84]} 0 0
[junit4] 2> 599793 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[85]} 0 0
[junit4] 2> 599795 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[86]} 0 0
[junit4] 2> 599797 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[87]} 0 0
[junit4] 2> 599799 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[88]} 0 0
[junit4] 2> 599801 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[89]} 0 0
[junit4] 2> 599803 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[90]} 0 0
[junit4] 2> 599805 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[91]} 0 0
[junit4] 2> 599807 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[92]} 0 0
[junit4] 2> 599810 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[93]} 0 0
[junit4] 2> 599812 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[94]} 0 0
[junit4] 2> 599823 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[95]} 0 0
[junit4] 2> 599825 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[96]} 0 0
[junit4] 2> 599830 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[97]} 0 0
[junit4] 2> 599832 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[98]} 0 0
[junit4] 2> 599834 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[99]} 0 0
[junit4] 2> 599849 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[100]} 0 12
[junit4] 2> 599853 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[101]} 0 0
[junit4] 2> 599855 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[102]} 0 0
[junit4] 2> 599857 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[103]} 0 0
[junit4] 2> 599860 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[104]} 0 1
[junit4] 2> 599862 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[105]} 0 0
[junit4] 2> 599864 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[106]} 0 0
[junit4] 2> 599866 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[107]} 0 0
[junit4] 2> 599869 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[108]} 0 0
[junit4] 2> 599872 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[109]} 0 0
[junit4] 2> 599874 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[110]} 0 0
[junit4] 2> 599877 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[111]} 0 0
[junit4] 2> 599880 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[112]} 0 0
[junit4] 2> 599883 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[113]} 0 0
[junit4] 2> 599886 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[114]} 0 0
[junit4] 2> 599889 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[115]} 0 0
[junit4] 2> 599892 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[116]} 0 0
[junit4] 2> 599895 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[117]} 0 0
[junit4] 2> 599898 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[118]} 0 0
[junit4] 2> 599901 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[119]} 0 0
[junit4] 2> 599903 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[120]} 0 0
[junit4] 2> 599906 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[121]} 0 0
[junit4] 2> 599909 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[122]} 0 0
[junit4] 2> 599912 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[123]} 0 0
[junit4] 2> 599915 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[124]} 0 0
[junit4] 2> 599918 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[125]} 0 0
[junit4] 2> 599922 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[126]} 0 0
[junit4] 2> 599924 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[127]} 0 0
[junit4] 2> 599927 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[128]} 0 0
[junit4] 2> 599930 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[129]} 0 0
[junit4] 2> 599931 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[130]} 0 0
[junit4] 2> 599933 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[131]} 0 0
[junit4] 2> 599946 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[132]} 0 0
[junit4] 2> 599950 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[133]} 0 0
[junit4] 2> 599953 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[134]} 0 0
[junit4] 2> 599955 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[135]} 0 0
[junit4] 2> 599958 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[136]} 0 0
[junit4] 2> 599960 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[137]} 0 0
[junit4] 2> 599962 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[138]} 0 0
[junit4] 2> 599965 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[139]} 0 0
[junit4] 2> 599968 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[140]} 0 0
[junit4] 2> 599970 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[141]} 0 0
[junit4] 2> 599973 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[142]} 0 0
[junit4] 2> 599976 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[143]} 0 0
[junit4] 2> 599978 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[144]} 0 0
[junit4] 2> 599980 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[145]} 0 0
[junit4] 2> 599984 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[146]} 0 0
[junit4] 2> 599987 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[147]} 0 0
[junit4] 2> 599989 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[148]} 0 0
[junit4] 2> 599992 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[149]} 0 1
[junit4] 2> 599995 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[150]} 0 1
[junit4] 2> 599998 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[151]} 0 0
[junit4] 2> 600001 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[152]} 0 0
[junit4] 2> 600004 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[153]} 0 0
[junit4] 2> 600006 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[154]} 0 0
[junit4] 2> 600009 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[155]} 0 0
[junit4] 2> 600012 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[156]} 0 0
[junit4] 2> 600015 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[157]} 0 0
[junit4] 2> 600017 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[158]} 0 0
[junit4] 2> 600019 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[159]} 0 0
[junit4] 2> 600022 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[160]} 0 0
[junit4] 2> 600024 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[161]} 0 0
[junit4] 2> 600026 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[162]} 0 0
[junit4] 2> 600029 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[163]} 0 0
[junit4] 2> 600032 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[164]} 0 0
[junit4] 2> 600034 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[165]} 0 0
[junit4] 2> 600036 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[166]} 0 0
[junit4] 2> 600038 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[167]} 0 0
[junit4] 2> 600040 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[168]} 0 0
[junit4] 2> 600043 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[169]} 0 0
[junit4] 2> 600045 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[170]} 0 0
[junit4] 2> 600047 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[171]} 0 0
[junit4] 2> 600050 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[172]} 0 0
[junit4] 2> 600052 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[173]} 0 0
[junit4] 2> 600055 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[174]} 0 0
[junit4] 2> 600057 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[175]} 0 0
[junit4] 2> 600059 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[176]} 0 0
[junit4] 2> 600061 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[177]} 0 0
[junit4] 2> 600063 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[178]} 0 0
[junit4] 2> 600066 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[179]} 0 0
[junit4] 2> 600068 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[180]} 0 0
[junit4] 2> 600070 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[181]} 0 0
[junit4] 2> 600073 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[182]} 0 0
[junit4] 2> 600075 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[183]} 0 0
[junit4] 2> 600077 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[184]} 0 0
[junit4] 2> 600081 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[185]} 0 0
[junit4] 2> 600084 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[186]} 0 0
[junit4] 2> 600088 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[187]} 0 0
[junit4] 2> 600091 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[188]} 0 0
[junit4] 2> 600094 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[189]} 0 0
[junit4] 2> 600097 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[190]} 0 0
[junit4] 2> 600099 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[191]} 0 0
[junit4] 2> 600102 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[192]} 0 0
[junit4] 2> 600105 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[193]} 0 0
[junit4] 2> 600106 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[194]} 0 0
[junit4] 2> 600108 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[195]} 0 0
[junit4] 2> 600111 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[196]} 0 0
[junit4] 2> 600113 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[197]} 0 0
[junit4] 2> 600115 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[198]} 0 0
[junit4] 2> 600118 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[199]} 0 0
[junit4] 2> 600121 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[200]} 0 0
[junit4] 2> 600124 T1756 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[201]} 0 0
[junit4] 2> 600126 T1757 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[202]} 0 0
[junit4] 2> 600128 T1752 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[203]} 0 0
[junit4] 2> 600131 T1753 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[204]} 0 0
[junit4] 2> 600134 T1754 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[205]} 0 0
[junit4] 2> 600135 T1755 C1065 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[206]} 0 0
[junit4] 2> ASYNC NEW_CORE C1066 name=collection1 org.apache.solr.core.SolrCore@1fa2aaf
[junit4] 2> 600144 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[207]} 0 0
[junit4] 2> 600146 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[208]} 0 0
[junit4] 2> 600149 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[209]} 0 0
[junit4] 2> 600152 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[210]} 0 0
[junit4] 2> 600154 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[211]} 0 0
[junit4] 2> 600157 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[212]} 0 0
[junit4] 2> 600160 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[213]} 0 0
[junit4] 2> 600163 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[214]} 0 0
[junit4] 2> 600164 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[215]} 0 0
[junit4] 2> 600166 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[216]} 0 0
[junit4] 2> 600168 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[217]} 0 0
[junit4] 2> 600170 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[218]} 0 0
[junit4] 2> 600173 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[219]} 0 0
[junit4] 2> 600175 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[220]} 0 0
[junit4] 2> 600177 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[221]} 0 0
[junit4] 2> 600180 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[222]} 0 0
[junit4] 2> 600183 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[223]} 0 0
[junit4] 2> 600186 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[224]} 0 0
[junit4] 2> 600189 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[225]} 0 0
[junit4] 2> 600191 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[226]} 0 0
[junit4] 2> 600193 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[227]} 0 0
[junit4] 2> 600195 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[228]} 0 0
[junit4] 2> 600198 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[229]} 0 0
[junit4] 2> 600202 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[230]} 0 0
[junit4] 2> 600206 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[231]} 0 0
[junit4] 2> 600210 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[232]} 0 0
[junit4] 2> 600212 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[233]} 0 0
[junit4] 2> 600215 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[234]} 0 0
[junit4] 2> 600218 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[235]} 0 0
[junit4] 2> 600222 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[236]} 0 0
[junit4] 2> 600224 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[237]} 0 0
[junit4] 2> 600228 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[238]} 0 0
[junit4] 2> 600231 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[239]} 0 0
[junit4] 2> 600234 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[240]} 0 0
[junit4] 2> 600237 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[241]} 0 0
[junit4] 2> 600240 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[242]} 0 0
[junit4] 2> 600244 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[243]} 0 0
[junit4] 2> 600246 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[244]} 0 0
[junit4] 2> 600249 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[245]} 0 0
[junit4] 2> 600251 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[246]} 0 0
[junit4] 2> 600253 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[247]} 0 0
[junit4] 2> 600256 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[248]} 0 0
[junit4] 2> 600259 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[249]} 0 0
[junit4] 2> 600262 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[250]} 0 0
[junit4] 2> 600265 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[251]} 0 0
[junit4] 2> 600268 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[252]} 0 0
[junit4] 2> 600270 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[253]} 0 0
[junit4] 2> 600273 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[254]} 0 0
[junit4] 2> 600276 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[255]} 0 0
[junit4] 2> 600279 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[256]} 0 0
[junit4] 2> 600280 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[257]} 0 0
[junit4] 2> 600282 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[258]} 0 0
[junit4] 2> 600284 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[259]} 0 0
[junit4] 2> 600287 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[260]} 0 0
[junit4] 2> 600290 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[261]} 0 0
[junit4] 2> 600292 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[262]} 0 0
[junit4] 2> 600295 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[263]} 0 0
[junit4] 2> 600298 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[264]} 0 0
[junit4] 2> 600301 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[265]} 0 0
[junit4] 2> 600304 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[266]} 0 0
[junit4] 2> 600307 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[267]} 0 0
[junit4] 2> 600310 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[268]} 0 1
[junit4] 2> 600312 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[269]} 0 0
[junit4] 2> 600315 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[270]} 0 0
[junit4] 2> 600318 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[271]} 0 0
[junit4] 2> 600321 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[272]} 0 0
[junit4] 2> 600324 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[273]} 0 0
[junit4] 2> 600327 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[274]} 0 0
[junit4] 2> 600330 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[275]} 0 0
[junit4] 2> 600332 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[276]} 0 0
[junit4] 2> 600334 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[277]} 0 0
[junit4] 2> 600337 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[278]} 0 0
[junit4] 2> 600339 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[279]} 0 0
[junit4] 2> 600341 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[280]} 0 0
[junit4] 2> 600343 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[281]} 0 0
[junit4] 2> 600345 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[282]} 0 0
[junit4] 2> 600347 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[283]} 0 0
[junit4] 2> 600350 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[284]} 0 0
[junit4] 2> 600352 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[285]} 0 0
[junit4] 2> 600355 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[286]} 0 0
[junit4] 2> 600357 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[287]} 0 0
[junit4] 2> 600359 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[288]} 0 0
[junit4] 2> 600362 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[289]} 0 0
[junit4] 2> 600364 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[290]} 0 0
[junit4] 2> 600366 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[291]} 0 0
[junit4] 2> 600368 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[292]} 0 0
[junit4] 2> 600369 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[293]} 0 0
[junit4] 2> 600372 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[294]} 0 0
[junit4] 2> 600374 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[295]} 0 0
[junit4] 2> 600377 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[296]} 0 0
[junit4] 2> 600379 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[297]} 0 0
[junit4] 2> 600381 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[298]} 0 0
[junit4] 2> 600384 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[299]} 0 0
[junit4] 2> 600387 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[300]} 0 0
[junit4] 2> 600389 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[301]} 0 0
[junit4] 2> 600391 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[302]} 0 0
[junit4] 2> 600393 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[303]} 0 0
[junit4] 2> 600395 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[304]} 0 0
[junit4] 2> 600397 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[305]} 0 0
[junit4] 2> 600400 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[306]} 0 0
[junit4] 2> 600402 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[307]} 0 0
[junit4] 2> 600404 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[308]} 0 0
[junit4] 2> 600408 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[309]} 0 0
[junit4] 2> 600411 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[310]} 0 0
[junit4] 2> 600414 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[311]} 0 0
[junit4] 2> 600417 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[312]} 0 0
[junit4] 2> 600420 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[313]} 0 0
[junit4] 2> 600422 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[314]} 0 0
[junit4] 2> 600424 T1757 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[315]} 0 0
[junit4] 2> 600426 T1752 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[316]} 0 0
[junit4] 2> 600429 T1754 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[317]} 0 0
[junit4] 2> 600431 T1753 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[318]} 0 0
[junit4] 2> 600433 T1755 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[319]} 0 0
[junit4] 2> 600436 T1756 C1066 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2
[...truncated too long message...]
nit4] 2> 670145 T2409 C1170 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 670145 T2421 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a3ed59 main{StandardDirectoryReader(segments_3:5:nrt _0(5.0):C1 _1(5.0):C1)}
[junit4] 2> 670145 T2409 C1170 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 3
[junit4] 2> 670153 T2411 C1170 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=id:2001&wt=javabin&version=2} hits=1 status=0 QTime=5
[junit4] 2> 670154 T1721 oas.SolrTestCaseJ4.tearDown ###Ending doTestIndexAndConfigAliasReplication
[junit4] 2> 670167 T1721 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=27594629
[junit4] 2> 670168 T1721 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1967b5d
[junit4] 2> 670169 T1721 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 670170 T1721 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 670170 T1721 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 670170 T1721 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 670171 T1721 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 670171 T1721 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 670172 T1721 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867668\master\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867668\master\collection1\data\;done=false>>]
[junit4] 2> 670173 T1721 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867668\master\collection1\data\
[junit4] 2> 670173 T1721 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867668\master\collection1\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867668\master\collection1\data\index;done=false>>]
[junit4] 2> 670174 T1721 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867668\master\collection1\data\index
[junit4] 2> 670174 T1721 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 670237 T1721 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2133300
[junit4] 2> 670238 T1721 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@f55fad
[junit4] 2> 670238 T1721 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 670240 T1721 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 670240 T1721 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 670240 T1721 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 670241 T1721 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 670241 T1721 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 670242 T1721 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867822\slave\collection1\data\index.20130819191431000 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867822\slave\collection1\data\index.20130819191431000;done=false>>]
[junit4] 2> 670242 T1721 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867822\slave\collection1\data\index.20130819191431000
[junit4] 2> 670242 T1721 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867822\slave\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867822\slave\collection1\data\;done=false>>]
[junit4] 2> 670242 T1721 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1376928867822\slave\collection1\data\
[junit4] 2> 670244 T1721 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 670332 T1721 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=en_GB, timezone=Europe/Tiraspol
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.8.0-ea (32-bit)/cpus=2,threads=1,free=32664512,total=108171264
[junit4] 2> NOTE: All tests run in this JVM: [SpatialFilterTest, SampleTest, SolrInfoMBeanTest, BJQParserTest, LeaderElectionTest, RequiredFieldsTest, SolrTestCaseJ4Test, AddBlockUpdateTest, TestFunctionQuery, HighlighterTest, TestFastWriter, TestGroupingSearch, ReturnFieldsTest, StressHdfsTest, CSVRequestHandlerTest, TestPostingsSolrHighlighter, HdfsSyncSliceTest, ZkNodePropsTest, LukeRequestHandlerTest, TestImplicitCoreProperties, TestSolrQueryParser, HdfsChaosMonkeySafeLeaderTest, DistributedTermsComponentTest, CoreAdminHandlerTest, ChaosMonkeySafeLeaderTest, SolrRequestParserTest, LoggingHandlerTest, TestFastLRUCache, SortByFunctionTest, OverseerCollectionProcessorTest, TestSerializedLuceneMatchVersion, DistanceFunctionTest, TestLMJelinekMercerSimilarityFactory, TestSweetSpotSimilarityFactory, AlternateDirectoryTest, TestClassNameShortening, TestSuggestSpellingConverter, TestSchemaSimilarityResource, TestCloudManagedSchema, CoreMergeIndexesAdminHandlerTest, TestSolrDeletionPolicy1, TestSolrCoreProperties, FileBasedSpellCheckerTest, SoftAutoCommitTest, TestWriterPerf, DocValuesTest, TestXIncludeConfig, AutoCommitTest, DirectUpdateHandlerTest, SOLR749Test, AliasIntegrationTest, SolrIndexSplitterTest, RecoveryZkTest, TestLuceneMatchVersion, TestCharFilters, TestJmxMonitoredMap, HdfsCollectionsAPIDistributedZkTest, TestDistributedSearch, TestDefaultSearchFieldResource, TestFastOutputStream, JsonLoaderTest, DocumentAnalysisRequestHandlerTest, TestPartialUpdateDeduplication, TestUpdate, TestStressLucene, TestRemoteStreaming, TestZkChroot, BadComponentTest, TestInfoStreamLogging, TestFieldCollectionResource, StandardRequestHandlerTest, SuggesterTSTTest, TestUtils, DateMathParserTest, TestPhraseSuggestions, TestElisionMultitermQuery, TestSurroundQueryParser, TestReplicationHandler]
[junit4] Completed in 71.41s, 14 tests, 1 failure <<< FAILURES!
[...truncated 743 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:389: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:369: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:450: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1230: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:873: There were test failures: 322 suites, 1372 tests, 1 failure, 43 ignored (11 assumptions)
Total time: 70 minutes 47 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-ea-b102 -server -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure