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/06/30 22:02:56 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_25) - Build #
6383 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/6383/
Java: 32bit/jdk1.7.0_25 -server -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestStressReplication
Error Message:
timed out waiting for collection1 startAt time to exceed: Mon Jul 01 04:56:51 IRKT 2013
Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Mon Jul 01 04:56:51 IRKT 2013
at __randomizedtesting.SeedInfo.seed([5C995336878A5595:873253F082A23C26]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1473)
at org.apache.solr.handler.TestReplicationHandler.doTestStressReplication(TestReplicationHandler.java:777)
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:606)
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 9723 lines...]
[junit4:junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4:junit4] 2> 762126 T3038 oas.SolrTestCaseJ4.setUp ###Starting doTestStressReplication
[junit4:junit4] 2> 762129 T3038 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 762132 T3038 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54583
[junit4:junit4] 2> 762132 T3038 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 762133 T3038 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 762133 T3038 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master
[junit4:junit4] 2> 762133 T3038 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/solr.xml
[junit4:junit4] 2> 762134 T3038 oasc.CoreContainer.<init> New CoreContainer 33048946
[junit4:junit4] 2> 762134 T3038 oasc.CoreContainer$Initializer.initialize no solr.xml found. using default old-style solr.xml
[junit4:junit4] 2> 762134 T3038 oasc.CoreContainer.load Loading CoreContainer using Solr Home: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/'
[junit4:junit4] 2> 762135 T3038 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/'
[junit4:junit4] 2> 762178 T3038 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 762179 T3038 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 762179 T3038 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 762179 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 762180 T3038 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 762180 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 762180 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 762181 T3038 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 762181 T3038 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 762181 T3038 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 762184 T3038 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 762187 T3048 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1
[junit4:junit4] 2> 762188 T3048 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/'
[junit4:junit4] 2> 762214 T3048 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 762277 T3048 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 762278 T3048 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 762280 T3048 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 762290 T3048 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 762291 T3048 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 762291 T3048 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data/
[junit4:junit4] 2> 762291 T3048 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4] 2> 762291 T3048 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data
[junit4:junit4] 2> 762292 T3048 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data/index/
[junit4:junit4] 2> 762292 T3048 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 762292 T3048 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data/index
[junit4:junit4] 2> 762293 T3048 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@11e23cd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@af39ab),segFN=segments_1,generation=1}
[junit4:junit4] 2> 762293 T3048 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 762294 T3048 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 762294 T3048 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 762294 T3048 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 762295 T3048 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 762295 T3048 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 762295 T3048 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 762297 T3048 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 762299 T3048 oass.SolrIndexSearcher.<init> Opening Searcher@2c2b9d main
[junit4:junit4] 2> 762299 T3048 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 762299 T3048 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 762300 T3048 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4:junit4] 2> 762300 T3048 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 762300 T3048 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 762300 T3049 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2c2b9d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 762300 T3038 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 762301 T3038 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 762302 T3038 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 762307 T3038 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 762308 T3038 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51479
[junit4:junit4] 2> 762309 T3038 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 762309 T3038 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 762310 T3038 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave
[junit4:junit4] 2> 762310 T3038 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/solr.xml
[junit4:junit4] 2> 762311 T3038 oasc.CoreContainer.<init> New CoreContainer 29445833
[junit4:junit4] 2> 762311 T3038 oasc.CoreContainer$Initializer.initialize no solr.xml found. using default old-style solr.xml
[junit4:junit4] 2> 762311 T3038 oasc.CoreContainer.load Loading CoreContainer using Solr Home: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/'
[junit4:junit4] 2> 762312 T3038 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/'
[junit4:junit4] 2> 762355 T3038 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 762356 T3038 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 762356 T3038 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 762356 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 762357 T3038 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 762357 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 762357 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 762358 T3038 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 762358 T3038 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 762358 T3038 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 762361 T3038 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 762363 T3060 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1
[junit4:junit4] 2> 762364 T3060 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/'
[junit4:junit4] 2> 762391 T3060 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 762419 T3060 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 762420 T3060 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 762422 T3060 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 762432 T3060 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 762432 T3060 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 762433 T3060 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/
[junit4:junit4] 2> 762433 T3060 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4] 2> 762433 T3060 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data
[junit4:junit4] 2> 762434 T3060 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index/
[junit4:junit4] 2> 762434 T3060 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 762434 T3060 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index
[junit4:junit4] 2> 762435 T3060 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@114680c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@cdeafd),segFN=segments_1,generation=1}
[junit4:junit4] 2> 762435 T3060 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 762436 T3060 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 762436 T3060 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 762437 T3060 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 762437 T3060 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 762437 T3060 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 762437 T3060 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 762438 T3060 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 762440 T3060 oass.SolrIndexSearcher.<init> Opening Searcher@18419e1 main
[junit4:junit4] 2> 762440 T3060 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 762441 T3060 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 762442 T3060 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4:junit4] 2> 762442 T3060 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 762442 T3061 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18419e1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 762443 T3038 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 762444 T3038 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 762444 T3038 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 762470 T3038 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=29445833
[junit4:junit4] 2> 762471 T3038 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@50319a
[junit4:junit4] 2> 762471 T3038 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:junit4] 2> 762472 T3038 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 762472 T3038 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 762473 T3038 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 762474 T3038 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 762474 T3038 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 762475 T3038 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data;done=false>>]
[junit4:junit4] 2> 762475 T3038 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data
[junit4:junit4] 2> 762475 T3038 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index;done=false>>]
[junit4:junit4] 2> 762476 T3038 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index
[junit4:junit4] 2> 762476 T3038 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4] 2> 762528 T3038 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 762530 T3038 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47833
[junit4:junit4] 2> 762531 T3038 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 762531 T3038 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 762531 T3038 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave
[junit4:junit4] 2> 762532 T3038 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/solr.xml
[junit4:junit4] 2> 762532 T3038 oasc.CoreContainer.<init> New CoreContainer 4841855
[junit4:junit4] 2> 762532 T3038 oasc.CoreContainer$Initializer.initialize no solr.xml found. using default old-style solr.xml
[junit4:junit4] 2> 762533 T3038 oasc.CoreContainer.load Loading CoreContainer using Solr Home: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/'
[junit4:junit4] 2> 762533 T3038 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/'
[junit4:junit4] 2> 762611 T3038 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 762612 T3038 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 762612 T3038 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 762613 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 762613 T3038 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 762613 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 762614 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 762614 T3038 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 762614 T3038 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 762615 T3038 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 762617 T3038 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 762621 T3073 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1
[junit4:junit4] 2> 762622 T3073 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/'
[junit4:junit4] 2> 762644 T3073 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 762671 T3073 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 762672 T3073 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 762674 T3073 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 762683 T3073 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 762684 T3073 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 762684 T3073 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/
[junit4:junit4] 2> 762685 T3073 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4] 2> 762685 T3073 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data
[junit4:junit4] 2> 762685 T3073 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index/
[junit4:junit4] 2> 762685 T3073 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 762686 T3073 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index
[junit4:junit4] 2> 762687 T3073 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@110c030 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ef870c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 762687 T3073 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 762688 T3073 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 762688 T3073 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 762688 T3073 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 762688 T3073 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 762688 T3073 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 762689 T3073 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 762690 T3073 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 762691 T3073 oass.SolrIndexSearcher.<init> Opening Searcher@e0cd5e main
[junit4:junit4] 2> 762692 T3073 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 762692 T3073 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 762692 T3073 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 762692 T3073 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 762692 T3074 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e0cd5e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 762693 T3038 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 762693 T3038 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 762694 T3038 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 762718 T3038 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=33048946
[junit4:junit4] 2> 762719 T3038 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@e5e9a6
[junit4:junit4] 2> 762720 T3038 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:junit4] 2> 762720 T3038 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 762720 T3038 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 762721 T3038 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 762721 T3038 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 762722 T3038 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 762722 T3038 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data;done=false>>]
[junit4:junit4] 2> 762723 T3038 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data
[junit4:junit4] 2> 762723 T3038 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data/index;done=false>>]
[junit4:junit4] 2> 762723 T3038 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data/index
[junit4:junit4] 2> 762724 T3038 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4] 2> 762776 T3038 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 762778 T3038 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58865
[junit4:junit4] 2> 762779 T3038 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 762779 T3038 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 762780 T3038 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master
[junit4:junit4] 2> 762780 T3038 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/solr.xml
[junit4:junit4] 2> 762780 T3038 oasc.CoreContainer.<init> New CoreContainer 15967081
[junit4:junit4] 2> 762781 T3038 oasc.CoreContainer$Initializer.initialize no solr.xml found. using default old-style solr.xml
[junit4:junit4] 2> 762781 T3038 oasc.CoreContainer.load Loading CoreContainer using Solr Home: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/'
[junit4:junit4] 2> 762781 T3038 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/'
[junit4:junit4] 2> 762825 T3038 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 762826 T3038 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 762826 T3038 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 762827 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 762827 T3038 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 762827 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 762828 T3038 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 762828 T3038 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 762829 T3038 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 762829 T3038 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 762832 T3038 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 762835 T3085 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1
[junit4:junit4] 2> 762835 T3085 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/'
[junit4:junit4] 2> 762858 T3085 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 762918 T3085 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 762918 T3085 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 762920 T3085 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 762930 T3085 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 762931 T3085 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 762931 T3085 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data/
[junit4:junit4] 2> 762931 T3085 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4] 2> 762931 T3085 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data
[junit4:junit4] 2> 762932 T3085 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data/index/
[junit4:junit4] 2> 762932 T3085 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 762932 T3085 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208398/master/collection1/data/index
[junit4:junit4] 2> 762933 T3085 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_1,generation=1}
[junit4:junit4] 2> 762933 T3085 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 762934 T3085 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 762935 T3085 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 762935 T3085 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 762935 T3085 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 762935 T3085 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 762935 T3085 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 762936 T3085 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 762938 T3085 oass.SolrIndexSearcher.<init> Opening Searcher@16505f4 main
[junit4:junit4] 2> 762938 T3085 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 762939 T3085 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 762939 T3085 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml
[junit4:junit4] 2> 762939 T3085 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_1,generation=1}
[junit4:junit4] 2> 762940 T3085 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 762940 T3085 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 762940 T3085 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 762940 T3086 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16505f4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 762940 T3038 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 762941 T3038 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 762941 T3038 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C1902 name=collection1 org.apache.solr.core.SolrCore@19bf23b
[junit4:junit4] 2> 762949 T3081 C1902 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4] 2> 762950 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:*} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C1903 name=collection1 org.apache.solr.core.SolrCore@1f96269
[junit4:junit4] 2> 762954 T3070 C1903 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4] 2> 762956 T3070 C1903 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@110c030 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ef870c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 762956 T3070 C1903 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 762957 T3070 C1903 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:*} 0 3
[junit4:junit4] 2> 762959 T3071 C1903 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 762960 T3071 C1903 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@110c030 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ef870c),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@110c030 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ef870c),segFN=segments_2,generation=2}
[junit4:junit4] 2> 762960 T3071 C1903 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 762960 T3071 C1903 oass.SolrIndexSearcher.<init> Opening Searcher@f736fa main
[junit4:junit4] 2> 762961 T3071 C1903 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 762961 T3074 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f736fa main{StandardDirectoryReader(segments_2:2:nrt)}
[junit4:junit4] 2> 762961 T3071 C1903 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 2
[junit4:junit4] 2> 762964 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0]} 0 0
[junit4:junit4] 2> 762966 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 0
[junit4:junit4] 2> 762968 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 0
[junit4:junit4] 2> 762970 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[3]} 0 0
[junit4:junit4] 2> 762972 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[4]} 0 0
[junit4:junit4] 2> 762973 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[5]} 0 0
[junit4:junit4] 2> 762975 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[6]} 0 0
[junit4:junit4] 2> 762977 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[7]} 0 0
[junit4:junit4] 2> 762979 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[8]} 0 1
[junit4:junit4] 2> 762980 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[9]} 0 0
[junit4:junit4] 2> 762982 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[10]} 0 0
[junit4:junit4] 2> 762984 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[11]} 0 0
[junit4:junit4] 2> 762985 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[12]} 0 0
[junit4:junit4] 2> 762987 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[13]} 0 0
[junit4:junit4] 2> 762989 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[14]} 0 0
[junit4:junit4] 2> 762991 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[15]} 0 0
[junit4:junit4] 2> 762993 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[16]} 0 0
[junit4:junit4] 2> 762995 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[17]} 0 0
[junit4:junit4] 2> 762996 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[18]} 0 0
[junit4:junit4] 2> 762998 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[19]} 0 0
[junit4:junit4] 2> 763000 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[20]} 0 0
[junit4:junit4] 2> 763002 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[21]} 0 0
[junit4:junit4] 2> 763003 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[22]} 0 0
[junit4:junit4] 2> 763005 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[23]} 0 0
[junit4:junit4] 2> 763007 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[24]} 0 0
[junit4:junit4] 2> 763009 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[25]} 0 1
[junit4:junit4] 2> 763010 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[26]} 0 0
[junit4:junit4] 2> 763012 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[27]} 0 0
[junit4:junit4] 2> 763014 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[28]} 0 0
[junit4:junit4] 2> 763016 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[29]} 0 0
[junit4:junit4] 2> 763017 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[30]} 0 0
[junit4:junit4] 2> 763019 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[31]} 0 0
[junit4:junit4] 2> 763021 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[32]} 0 0
[junit4:junit4] 2> 763023 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[33]} 0 0
[junit4:junit4] 2> 763024 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[34]} 0 0
[junit4:junit4] 2> 763026 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[35]} 0 0
[junit4:junit4] 2> 763028 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[36]} 0 0
[junit4:junit4] 2> 763030 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[37]} 0 1
[junit4:junit4] 2> 763031 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[38]} 0 0
[junit4:junit4] 2> 763033 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[39]} 0 0
[junit4:junit4] 2> 763035 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[40]} 0 0
[junit4:junit4] 2> 763037 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[41]} 0 1
[junit4:junit4] 2> 763038 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[42]} 0 0
[junit4:junit4] 2> 763040 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[43]} 0 0
[junit4:junit4] 2> 763042 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[44]} 0 0
[junit4:junit4] 2> 763044 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[45]} 0 0
[junit4:junit4] 2> 763045 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[46]} 0 0
[junit4:junit4] 2> 763047 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[47]} 0 0
[junit4:junit4] 2> 763049 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[48]} 0 0
[junit4:junit4] 2> 763051 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[49]} 0 1
[junit4:junit4] 2> 763052 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[50]} 0 0
[junit4:junit4] 2> 763054 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[51]} 0 0
[junit4:junit4] 2> 763056 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[52]} 0 0
[junit4:junit4] 2> 763058 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[53]} 0 0
[junit4:junit4] 2> 763059 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[54]} 0 0
[junit4:junit4] 2> 763061 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[55]} 0 0
[junit4:junit4] 2> 763063 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[56]} 0 0
[junit4:junit4] 2> 763065 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[57]} 0 1
[junit4:junit4] 2> 763066 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[58]} 0 0
[junit4:junit4] 2> 763068 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[59]} 0 0
[junit4:junit4] 2> 763070 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[60]} 0 0
[junit4:junit4] 2> 763072 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[61]} 0 0
[junit4:junit4] 2> 763074 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[62]} 0 1
[junit4:junit4] 2> 763075 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[63]} 0 0
[junit4:junit4] 2> 763077 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[64]} 0 0
[junit4:junit4] 2> 763079 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[65]} 0 0
[junit4:junit4] 2> 763081 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[66]} 0 0
[junit4:junit4] 2> 763082 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[67]} 0 0
[junit4:junit4] 2> 763084 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[68]} 0 0
[junit4:junit4] 2> 763086 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[69]} 0 0
[junit4:junit4] 2> 763089 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[70]} 0 0
[junit4:junit4] 2> 763090 T3081 C1902 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 763092 T3081 C1902 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_2,generation=2}
[junit4:junit4] 2> 763093 T3081 C1902 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 763094 T3081 C1902 oass.SolrIndexSearcher.<init> Opening Searcher@9c0145 main
[junit4:junit4] 2> 763094 T3081 C1902 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 763094 T3086 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9c0145 main{StandardDirectoryReader(segments_2:4:nrt _0(5.0):C71)}
[junit4:junit4] 2> 763095 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> 763098 T3082 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=71 status=0 QTime=1
[junit4:junit4] 2> 763101 T3072 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 763102 T3088 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4] 2> 763103 T3088 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 763103 T3083 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 763104 T3088 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 763104 T3088 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
[junit4:junit4] 2> 763104 T3088 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 763108 T3084 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=2
[junit4:junit4] 2> 763109 T3088 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
[junit4:junit4] 2> 763109 T3088 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045649381
[junit4:junit4] 2> 763109 T3088 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4) fullCopy=true
[junit4:junit4] 2> 763111 T3081 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_Lucene41WithOrds_0.tib&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 763114 T3082 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 763116 T3083 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_Lucene41WithOrds_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 763119 T3084 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 763121 T3081 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 763124 T3082 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_Lucene41WithOrds_0.tii&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 763126 T3083 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 763129 T3084 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 763132 T3081 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 763135 T3082 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 763136 T3088 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 763137 T3088 oash.SnapPuller.downloadConfFiles Starting download of configuration files from master: [{name=schema.xml, checksum=1505963717, size=1634}]
[junit4:junit4] 2> 763143 T3083 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filecontent&checksum=true&wt=filestream&cf=schema.xml&qt=/replication&generation=2} status=0 QTime=2
[junit4:junit4] 2> 763149 T3088 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130701045649381
[junit4:junit4] 2> 763150 T3088 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@110c030 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ef870c)
[junit4:junit4] 2> 763150 T3088 oash.SnapPuller.fetchLatestIndex Configuration files are modified, core will be reloaded
[junit4:junit4] 2> 763152 T3088 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@110c030 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ef870c)
[junit4:junit4] 2> 763152 T3090 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1
[junit4:junit4] 2> 763152 T3088 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 763153 T3090 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/'
[junit4:junit4] 2> 763153 T3088 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 763153 T3088 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 763154 T3088 oasc.SolrCore.getNewIndexDir New index directory detected: old=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index/ new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045649381
[junit4:junit4] 2> 763155 T3088 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_2,generation=2}
[junit4:junit4] 2> 763155 T3088 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 763156 T3088 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 763156 T3088 oass.SolrIndexSearcher.<init> Opening Searcher@18a6e64 main
[junit4:junit4] 2> 763157 T3074 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18a6e64 main{StandardDirectoryReader(segments_2:4:nrt _0(5.0):C71)}
[junit4:junit4] 2> 763157 T3070 C1903 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:58865/solr/replication&command=fetchindex&wait=true} status=0 QTime=55
[junit4:junit4] 2> 763158 T3070 C1903 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index;done=true>>]
[junit4:junit4] 2> 763158 T3070 C1903 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index
[junit4:junit4] 2> 763160 T3071 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 763179 T3090 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 763207 T3090 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 763207 T3090 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 763209 T3090 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 763220 T3090 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 763221 T3090 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/
[junit4:junit4] 2> 763221 T3090 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4] 2> 763222 T3090 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045649381
[junit4:junit4] 2> 763222 T3090 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 763223 T3090 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 763223 T3090 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 763223 T3090 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 763223 T3090 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 763223 T3090 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 763226 T3090 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 763228 T3090 oass.SolrIndexSearcher.<init> Opening Searcher@17a161e main
[junit4:junit4] 2> 763228 T3090 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 763229 T3090 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 763229 T3090 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 763229 T3090 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 763229 T3091 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17a161e main{StandardDirectoryReader(segments_2:4:nrt _0(5.0):C71)}
[junit4:junit4] 2> 763229 T3090 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 763229 T3090 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4] 2> 763231 T3090 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_2,generation=2}
[junit4:junit4] 2> 763231 T3090 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 763231 T3090 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 763231 T3090 oass.SolrIndexSearcher.<init> Opening Searcher@1b9396a main
[junit4:junit4] 2> 763232 T3090 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4] 2> 763232 T3091 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b9396a main{StandardDirectoryReader(segments_2:4:nrt _0(5.0):C71)}
[junit4:junit4] 2> 763232 T3090 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1f96269
[junit4:junit4] 2> 763232 T3090 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:junit4] 2> 763232 T3090 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 763362 T3072 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> ASYNC NEW_CORE C1904 name=collection1 org.apache.solr.core.SolrCore@168987a
[junit4:junit4] 2> 763368 T3070 C1904 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=71 status=0 QTime=0
[junit4:junit4] 2> 763372 T3084 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=1
[junit4:junit4] 2> 763374 T3082 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 763376 T3071 C1904 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=1
[junit4:junit4] 2> 763377 T3083 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 763379 T3069 C1904 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 763383 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[71]} 0 1
[junit4:junit4] 2> 763385 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[72]} 0 0
[junit4:junit4] 2> 763387 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[73]} 0 0
[junit4:junit4] 2> 763389 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[74]} 0 0
[junit4:junit4] 2> 763391 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[75]} 0 0
[junit4:junit4] 2> 763393 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[76]} 0 0
[junit4:junit4] 2> 763395 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[77]} 0 0
[junit4:junit4] 2> 763397 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[78]} 0 0
[junit4:junit4] 2> 763398 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[79]} 0 0
[junit4:junit4] 2> 763400 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[80]} 0 0
[junit4:junit4] 2> 763402 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[81]} 0 0
[junit4:junit4] 2> 763404 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[82]} 0 0
[junit4:junit4] 2> 763405 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[83]} 0 0
[junit4:junit4] 2> 763407 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[84]} 0 0
[junit4:junit4] 2> 763409 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[85]} 0 0
[junit4:junit4] 2> 763411 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[86]} 0 0
[junit4:junit4] 2> 763412 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[87]} 0 0
[junit4:junit4] 2> 763414 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[88]} 0 0
[junit4:junit4] 2> 763416 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[89]} 0 0
[junit4:junit4] 2> 763418 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[90]} 0 0
[junit4:junit4] 2> 763420 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[91]} 0 1
[junit4:junit4] 2> 763421 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[92]} 0 0
[junit4:junit4] 2> 763423 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[93]} 0 0
[junit4:junit4] 2> 763425 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[94]} 0 0
[junit4:junit4] 2> 763427 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[95]} 0 0
[junit4:junit4] 2> 763428 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[96]} 0 0
[junit4:junit4] 2> 763430 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[97]} 0 0
[junit4:junit4] 2> 763432 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[98]} 0 0
[junit4:junit4] 2> 763434 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[99]} 0 0
[junit4:junit4] 2> 763435 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[100]} 0 0
[junit4:junit4] 2> 763437 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[101]} 0 0
[junit4:junit4] 2> 763439 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[102]} 0 1
[junit4:junit4] 2> 763440 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[103]} 0 0
[junit4:junit4] 2> 763442 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[104]} 0 0
[junit4:junit4] 2> 763444 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[105]} 0 0
[junit4:junit4] 2> 763445 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[106]} 0 0
[junit4:junit4] 2> 763447 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[107]} 0 0
[junit4:junit4] 2> 763449 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[108]} 0 0
[junit4:junit4] 2> 763451 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[109]} 0 0
[junit4:junit4] 2> 763453 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[110]} 0 0
[junit4:junit4] 2> 763455 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[111]} 0 0
[junit4:junit4] 2> 763457 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[112]} 0 0
[junit4:junit4] 2> 763459 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[113]} 0 1
[junit4:junit4] 2> 763461 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[114]} 0 1
[junit4:junit4] 2> 763462 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[115]} 0 0
[junit4:junit4] 2> 763464 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[116]} 0 0
[junit4:junit4] 2> 763466 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[117]} 0 0
[junit4:junit4] 2> 763468 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[118]} 0 0
[junit4:junit4] 2> 763470 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[119]} 0 1
[junit4:junit4] 2> 763471 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[120]} 0 0
[junit4:junit4] 2> 763473 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[121]} 0 0
[junit4:junit4] 2> 763475 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[122]} 0 0
[junit4:junit4] 2> 763477 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[123]} 0 1
[junit4:junit4] 2> 763478 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[124]} 0 0
[junit4:junit4] 2> 763480 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[125]} 0 0
[junit4:junit4] 2> 763482 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[126]} 0 0
[junit4:junit4] 2> 763484 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[127]} 0 0
[junit4:junit4] 2> 763485 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[128]} 0 0
[junit4:junit4] 2> 763487 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[129]} 0 0
[junit4:junit4] 2> 763489 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[130]} 0 0
[junit4:junit4] 2> 763491 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[131]} 0 1
[junit4:junit4] 2> 763492 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[132]} 0 0
[junit4:junit4] 2> 763494 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[133]} 0 0
[junit4:junit4] 2> 763496 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[134]} 0 0
[junit4:junit4] 2> 763498 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[135]} 0 0
[junit4:junit4] 2> 763499 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[136]} 0 0
[junit4:junit4] 2> 763501 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[137]} 0 0
[junit4:junit4] 2> 763503 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[138]} 0 0
[junit4:junit4] 2> 763505 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[139]} 0 0
[junit4:junit4] 2> 763506 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[140]} 0 0
[junit4:junit4] 2> 763508 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[141]} 0 0
[junit4:junit4] 2> 763510 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[142]} 0 0
[junit4:junit4] 2> 763512 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[143]} 0 0
[junit4:junit4] 2> 763514 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[144]} 0 1
[junit4:junit4] 2> 763515 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[145]} 0 0
[junit4:junit4] 2> 763517 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[146]} 0 0
[junit4:junit4] 2> 763519 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[147]} 0 0
[junit4:junit4] 2> 763521 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[148]} 0 0
[junit4:junit4] 2> 763522 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[149]} 0 0
[junit4:junit4] 2> 763524 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[150]} 0 0
[junit4:junit4] 2> 763526 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[151]} 0 0
[junit4:junit4] 2> 763528 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[152]} 0 0
[junit4:junit4] 2> 763530 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[153]} 0 0
[junit4:junit4] 2> 763532 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[154]} 0 0
[junit4:junit4] 2> 763533 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[155]} 0 0
[junit4:junit4] 2> 763535 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[156]} 0 0
[junit4:junit4] 2> 763537 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[157]} 0 0
[junit4:junit4] 2> 763539 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[158]} 0 0
[junit4:junit4] 2> 763541 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[159]} 0 0
[junit4:junit4] 2> 763543 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[160]} 0 0
[junit4:junit4] 2> 763544 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[161]} 0 0
[junit4:junit4] 2> 763546 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[162]} 0 0
[junit4:junit4] 2> 763548 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[163]} 0 0
[junit4:junit4] 2> 763550 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[164]} 0 0
[junit4:junit4] 2> 763552 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[165]} 0 0
[junit4:junit4] 2> 763554 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[166]} 0 0
[junit4:junit4] 2> 763556 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[167]} 0 0
[junit4:junit4] 2> 763558 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[168]} 0 1
[junit4:junit4] 2> 763560 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[169]} 0 1
[junit4:junit4] 2> 763561 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[170]} 0 0
[junit4:junit4] 2> 763563 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[171]} 0 0
[junit4:junit4] 2> 763565 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[172]} 0 0
[junit4:junit4] 2> 763567 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[173]} 0 0
[junit4:junit4] 2> 763569 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[174]} 0 0
[junit4:junit4] 2> 763571 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[175]} 0 0
[junit4:junit4] 2> 763573 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[176]} 0 0
[junit4:junit4] 2> 763575 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[177]} 0 1
[junit4:junit4] 2> 763576 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[178]} 0 0
[junit4:junit4] 2> 763578 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[179]} 0 0
[junit4:junit4] 2> 763580 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[180]} 0 0
[junit4:junit4] 2> 763582 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[181]} 0 0
[junit4:junit4] 2> 763583 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[182]} 0 0
[junit4:junit4] 2> 763585 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[183]} 0 0
[junit4:junit4] 2> 763587 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[184]} 0 0
[junit4:junit4] 2> 763590 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[185]} 0 1
[junit4:junit4] 2> 763591 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[186]} 0 0
[junit4:junit4] 2> 763593 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[187]} 0 0
[junit4:junit4] 2> 763595 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[188]} 0 0
[junit4:junit4] 2> 763597 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[189]} 0 0
[junit4:junit4] 2> 763599 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[190]} 0 0
[junit4:junit4] 2> 763600 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[191]} 0 0
[junit4:junit4] 2> 763602 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[192]} 0 0
[junit4:junit4] 2> 763604 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[193]} 0 0
[junit4:junit4] 2> 763606 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[194]} 0 0
[junit4:junit4] 2> 763608 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[195]} 0 1
[junit4:junit4] 2> 763609 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[196]} 0 0
[junit4:junit4] 2> 763612 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[197]} 0 0
[junit4:junit4] 2> 763615 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[198]} 0 1
[junit4:junit4] 2> 763617 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[199]} 0 0
[junit4:junit4] 2> 763620 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[200]} 0 0
[junit4:junit4] 2> 763622 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[201]} 0 0
[junit4:junit4] 2> 763624 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[202]} 0 0
[junit4:junit4] 2> 763627 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[203]} 0 0
[junit4:junit4] 2> 763629 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[204]} 0 0
[junit4:junit4] 2> 763631 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[205]} 0 0
[junit4:junit4] 2> 763632 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[206]} 0 0
[junit4:junit4] 2> 763634 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[207]} 0 0
[junit4:junit4] 2> 763636 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[208]} 0 0
[junit4:junit4] 2> 763638 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[209]} 0 0
[junit4:junit4] 2> 763639 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[210]} 0 0
[junit4:junit4] 2> 763641 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[211]} 0 0
[junit4:junit4] 2> 763643 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[212]} 0 0
[junit4:junit4] 2> 763644 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[213]} 0 0
[junit4:junit4] 2> 763646 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[214]} 0 0
[junit4:junit4] 2> 763648 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[215]} 0 0
[junit4:junit4] 2> 763649 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[216]} 0 0
[junit4:junit4] 2> 763651 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[217]} 0 0
[junit4:junit4] 2> 763653 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[218]} 0 0
[junit4:junit4] 2> 763655 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[219]} 0 1
[junit4:junit4] 2> 763656 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[220]} 0 0
[junit4:junit4] 2> 763658 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[221]} 0 0
[junit4:junit4] 2> 763660 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[222]} 0 0
[junit4:junit4] 2> 763661 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[223]} 0 0
[junit4:junit4] 2> 763663 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[224]} 0 0
[junit4:junit4] 2> 763665 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[225]} 0 0
[junit4:junit4] 2> 763667 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[226]} 0 1
[junit4:junit4] 2> 763668 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[227]} 0 0
[junit4:junit4] 2> 763670 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[228]} 0 0
[junit4:junit4] 2> 763672 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[229]} 0 0
[junit4:junit4] 2> 763674 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[230]} 0 1
[junit4:junit4] 2> 763675 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[231]} 0 0
[junit4:junit4] 2> 763677 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[232]} 0 0
[junit4:junit4] 2> 763679 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[233]} 0 0
[junit4:junit4] 2> 763681 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[234]} 0 0
[junit4:junit4] 2> 763683 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[235]} 0 0
[junit4:junit4] 2> 763685 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[236]} 0 0
[junit4:junit4] 2> 763687 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[237]} 0 1
[junit4:junit4] 2> 763688 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[238]} 0 0
[junit4:junit4] 2> 763690 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[239]} 0 0
[junit4:junit4] 2> 763692 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[240]} 0 0
[junit4:junit4] 2> 763693 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[241]} 0 0
[junit4:junit4] 2> 763695 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[242]} 0 0
[junit4:junit4] 2> 763697 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[243]} 0 1
[junit4:junit4] 2> 763698 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[244]} 0 0
[junit4:junit4] 2> 763700 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[245]} 0 0
[junit4:junit4] 2> 763702 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[246]} 0 0
[junit4:junit4] 2> 763703 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[247]} 0 0
[junit4:junit4] 2> 763705 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[248]} 0 0
[junit4:junit4] 2> 763707 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[249]} 0 0
[junit4:junit4] 2> 763708 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[250]} 0 0
[junit4:junit4] 2> 763710 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[251]} 0 0
[junit4:junit4] 2> 763712 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[252]} 0 0
[junit4:junit4] 2> 763713 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[253]} 0 0
[junit4:junit4] 2> 763715 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[254]} 0 0
[junit4:junit4] 2> 763717 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[255]} 0 0
[junit4:junit4] 2> 763719 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[256]} 0 1
[junit4:junit4] 2> 763720 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[257]} 0 0
[junit4:junit4] 2> 763722 T3083 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[258]} 0 0
[junit4:junit4] 2> 763724 T3084 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[259]} 0 0
[junit4:junit4] 2> 763726 T3082 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[260]} 0 0
[junit4:junit4] 2> 763727 T3081 C1902 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 763729 T3081 C1902 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_3,generation=3}
[junit4:junit4] 2> 763730 T3081 C1902 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 763730 T3081 C1902 oass.SolrIndexSearcher.<init> Opening Searcher@154d272 main
[junit4:junit4] 2> 763731 T3081 C1902 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 763731 T3086 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@154d272 main{StandardDirectoryReader(segments_3:6:nrt _0(5.0):C71 _1(5.0):C190)}
[junit4:junit4] 2> 763731 T3081 C1902 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 4
[junit4:junit4] 2> 763735 T3083 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=261 status=0 QTime=2
[junit4:junit4] 2> 763738 T3070 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 763740 T3092 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4] 2> 763741 T3092 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 763743 T3084 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 763744 T3092 oash.SnapPuller.fetchLatestIndex Master's generation: 3
[junit4:junit4] 2> 763744 T3092 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
[junit4:junit4] 2> 763744 T3092 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 763748 T3082 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=3&version=2} status=0 QTime=2
[junit4:junit4] 2> 763749 T3092 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 19
[junit4:junit4] 2> 763750 T3092 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650021
[junit4:junit4] 2> 763750 T3092 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@106ecf7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@18371fd) fullCopy=false
[junit4:junit4] 2> 763750 T3092 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41WithOrds_0.tib because it already exists
[junit4:junit4] 2> 763753 T3081 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 2> 763754 T3092 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41WithOrds_0.doc because it already exists
[junit4:junit4] 2> 763755 T3092 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4:junit4] 2> 763757 T3083 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 2> 763761 T3084 C1902 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_Lucene41WithOrds_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 2> 763786 T3092 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41WithOrds_0.tii because it already exists
[junit4:junit4] 2> 763787 T3092 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4:junit4] 2> ASYNC NEW_CORE C1905 name=collection1 org.apache.solr.core.SolrCore@19bf23b
[junit4:junit4] 2> 763788 T3082 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 2> 763791 T3081 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 2> 763793 T3083 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 2> 763796 T3084 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_Lucene41WithOrds_0.tii&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 2> 763799 T3082 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 2> 763800 T3092 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4:junit4] 2> 763801 T3081 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_Lucene41WithOrds_0.tib&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 2> 763802 T3092 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4:junit4] 2> 763802 T3092 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4:junit4] 2> 763803 T3092 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4:junit4] 2> 763804 T3083 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_3&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 2> 763805 T3092 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 763806 T3092 oash.SnapPuller.downloadConfFiles Starting download of configuration files from master: [{name=schema.xml, checksum=265618607, size=1508}]
[junit4:junit4] 2> 763808 T3084 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filecontent&checksum=true&wt=filestream&cf=schema.xml&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 2> 763827 T3092 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4:junit4] 2> 763828 T3092 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 763828 T3092 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 763829 T3092 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 763830 T3092 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_3,generation=3}
[junit4:junit4] 2> 763830 T3092 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 763831 T3092 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 763831 T3092 oash.SnapPuller.fetchLatestIndex Configuration files are modified, core will be reloaded
[junit4:junit4] 2> 763831 T3094 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1
[junit4:junit4] 2> 763832 T3094 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/'
[junit4:junit4] 2> 763832 T3092 oass.SolrIndexSearcher.<init> Opening Searcher@15e0032 main
[junit4:junit4] 2> 763833 T3091 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15e0032 main{StandardDirectoryReader(segments_3:6:nrt _0(5.0):C71 _1(5.0):C190)}
[junit4:junit4] 2> 763833 T3092 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650021 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650021;done=true>>]
[junit4:junit4] 2> 763833 T3092 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650021
[junit4:junit4] 2> ASYNC NEW_CORE C1906 name=collection1 org.apache.solr.core.SolrCore@168987a
[junit4:junit4] 2> 763833 T3071 C1906 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:58865/solr/replication&command=fetchindex&wait=true} status=0 QTime=93
[junit4:junit4] 2> 763836 T3072 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 763878 T3094 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 763907 T3094 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 763908 T3094 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 763910 T3094 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 763920 T3094 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 763921 T3094 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/
[junit4:junit4] 2> 763921 T3094 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4] 2> 763921 T3094 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045649381
[junit4:junit4] 2> 763922 T3094 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 763922 T3094 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 763922 T3094 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 763923 T3094 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 763923 T3094 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 763923 T3094 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 763925 T3094 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 763928 T3094 oass.SolrIndexSearcher.<init> Opening Searcher@69a938 main
[junit4:junit4] 2> 763928 T3094 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 763928 T3094 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 763929 T3094 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 763929 T3094 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 763929 T3096 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@69a938 main{StandardDirectoryReader(segments_3:6:nrt _0(5.0):C71 _1(5.0):C190)}
[junit4:junit4] 2> 763929 T3094 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 763929 T3094 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4] 2> 763931 T3094 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_3,generation=3}
[junit4:junit4] 2> 763931 T3094 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 763931 T3094 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 763932 T3094 oass.SolrIndexSearcher.<init> Opening Searcher@46fea1 main
[junit4:junit4] 2> 763932 T3094 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4] 2> 763932 T3094 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@168987a
[junit4:junit4] 2> 763932 T3096 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@46fea1 main{StandardDirectoryReader(segments_3:6:nrt _0(5.0):C71 _1(5.0):C190)}
[junit4:junit4] 2> 763932 T3094 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:junit4] 2> 763932 T3094 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 764039 T3070 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> ASYNC NEW_CORE C1907 name=collection1 org.apache.solr.core.SolrCore@f7221f
[junit4:junit4] 2> 764046 T3071 C1907 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=261 status=0 QTime=1
[junit4:junit4] 2> 764049 T3082 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 764050 T3083 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 764052 T3069 C1907 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 764054 T3084 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 764056 T3072 C1907 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 764059 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[261]} 0 0
[junit4:junit4] 2> 764061 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[262]} 0 0
[junit4:junit4] 2> 764063 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[263]} 0 0
[junit4:junit4] 2> 764065 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[264]} 0 0
[junit4:junit4] 2> 764067 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[265]} 0 1
[junit4:junit4] 2> 764068 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[266]} 0 0
[junit4:junit4] 2> 764070 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[267]} 0 0
[junit4:junit4] 2> 764072 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[268]} 0 0
[junit4:junit4] 2> 764074 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[269]} 0 0
[junit4:junit4] 2> 764076 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[270]} 0 0
[junit4:junit4] 2> 764078 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[271]} 0 0
[junit4:junit4] 2> 764080 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[272]} 0 0
[junit4:junit4] 2> 764082 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[273]} 0 1
[junit4:junit4] 2> 764083 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[274]} 0 0
[junit4:junit4] 2> 764085 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[275]} 0 0
[junit4:junit4] 2> 764087 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[276]} 0 0
[junit4:junit4] 2> 764089 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[277]} 0 0
[junit4:junit4] 2> 764090 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[278]} 0 0
[junit4:junit4] 2> 764092 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[279]} 0 0
[junit4:junit4] 2> 764094 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[280]} 0 0
[junit4:junit4] 2> 764096 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[281]} 0 0
[junit4:junit4] 2> 764098 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[282]} 0 1
[junit4:junit4] 2> 764100 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[283]} 0 0
[junit4:junit4] 2> 764101 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[284]} 0 0
[junit4:junit4] 2> 764103 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[285]} 0 0
[junit4:junit4] 2> 764105 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[286]} 0 0
[junit4:junit4] 2> 764107 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[287]} 0 0
[junit4:junit4] 2> 764108 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[288]} 0 0
[junit4:junit4] 2> 764110 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[289]} 0 0
[junit4:junit4] 2> 764112 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[290]} 0 0
[junit4:junit4] 2> 764114 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[291]} 0 1
[junit4:junit4] 2> 764117 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[292]} 0 0
[junit4:junit4] 2> 764119 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[293]} 0 1
[junit4:junit4] 2> 764120 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[294]} 0 0
[junit4:junit4] 2> 764122 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[295]} 0 0
[junit4:junit4] 2> 764124 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[296]} 0 0
[junit4:junit4] 2> 764126 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[297]} 0 0
[junit4:junit4] 2> 764128 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[298]} 0 0
[junit4:junit4] 2> 764129 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[299]} 0 0
[junit4:junit4] 2> 764131 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[300]} 0 0
[junit4:junit4] 2> 764133 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[301]} 0 0
[junit4:junit4] 2> 764134 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[302]} 0 0
[junit4:junit4] 2> 764136 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[303]} 0 0
[junit4:junit4] 2> 764138 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[304]} 0 0
[junit4:junit4] 2> 764139 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[305]} 0 0
[junit4:junit4] 2> 764141 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[306]} 0 0
[junit4:junit4] 2> 764143 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[307]} 0 0
[junit4:junit4] 2> 764144 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[308]} 0 0
[junit4:junit4] 2> 764146 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[309]} 0 0
[junit4:junit4] 2> 764148 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[310]} 0 0
[junit4:junit4] 2> 764150 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[311]} 0 0
[junit4:junit4] 2> 764151 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[312]} 0 0
[junit4:junit4] 2> 764153 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[313]} 0 0
[junit4:junit4] 2> 764155 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[314]} 0 0
[junit4:junit4] 2> 764156 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[315]} 0 0
[junit4:junit4] 2> 764158 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[316]} 0 0
[junit4:junit4] 2> 764160 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[317]} 0 0
[junit4:junit4] 2> 764162 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[318]} 0 1
[junit4:junit4] 2> 764163 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[319]} 0 0
[junit4:junit4] 2> 764165 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[320]} 0 0
[junit4:junit4] 2> 764167 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[321]} 0 0
[junit4:junit4] 2> 764169 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[322]} 0 0
[junit4:junit4] 2> 764172 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[323]} 0 1
[junit4:junit4] 2> 764174 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[324]} 0 0
[junit4:junit4] 2> 764176 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[325]} 0 0
[junit4:junit4] 2> 764178 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[326]} 0 0
[junit4:junit4] 2> 764180 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[327]} 0 0
[junit4:junit4] 2> 764183 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[328]} 0 1
[junit4:junit4] 2> 764185 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[329]} 0 0
[junit4:junit4] 2> 764188 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[330]} 0 1
[junit4:junit4] 2> 764190 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[331]} 0 0
[junit4:junit4] 2> 764192 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[332]} 0 0
[junit4:junit4] 2> 764195 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[333]} 0 0
[junit4:junit4] 2> 764197 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[334]} 0 0
[junit4:junit4] 2> 764200 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[335]} 0 0
[junit4:junit4] 2> 764202 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[336]} 0 0
[junit4:junit4] 2> 764205 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[337]} 0 1
[junit4:junit4] 2> 764207 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[338]} 0 0
[junit4:junit4] 2> 764209 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[339]} 0 0
[junit4:junit4] 2> 764211 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[340]} 0 0
[junit4:junit4] 2> 764213 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[341]} 0 0
[junit4:junit4] 2> 764215 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[342]} 0 1
[junit4:junit4] 2> 764216 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[343]} 0 0
[junit4:junit4] 2> 764218 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[344]} 0 0
[junit4:junit4] 2> 764220 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[345]} 0 0
[junit4:junit4] 2> 764221 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[346]} 0 0
[junit4:junit4] 2> 764223 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[347]} 0 0
[junit4:junit4] 2> 764225 T3081 C1905 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 764227 T3081 C1905 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_3,generation=3}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_4,generation=4}
[junit4:junit4] 2> 764227 T3081 C1905 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4:junit4] 2> 764228 T3081 C1905 oass.SolrIndexSearcher.<init> Opening Searcher@2f34aa main
[junit4:junit4] 2> 764229 T3081 C1905 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 764229 T3086 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2f34aa main{StandardDirectoryReader(segments_4:8:nrt _0(5.0):C71 _1(5.0):C190 _2(5.0):C87)}
[junit4:junit4] 2> 764229 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 4
[junit4:junit4] 2> 764232 T3082 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=348 status=0 QTime=1
[junit4:junit4] 2> 764235 T3070 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 764236 T3097 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4] 2> 764236 T3097 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 764237 T3083 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 764238 T3097 oash.SnapPuller.fetchLatestIndex Master's generation: 4
[junit4:junit4] 2> 764238 T3097 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
[junit4:junit4] 2> 764238 T3097 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 764240 T3084 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=4&version=2} status=0 QTime=1
[junit4:junit4] 2> 764240 T3097 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 28
[junit4:junit4] 2> 764241 T3097 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650513
[junit4:junit4] 2> 764241 T3097 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@c7815b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1bbe72d) fullCopy=false
[junit4:junit4] 2> 764243 T3081 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4:junit4] 2> 764246 T3082 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_Lucene41WithOrds_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4:junit4] 2> 764247 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41WithOrds_0.tib because it already exists
[junit4:junit4] 2> 764247 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41WithOrds_0.doc because it already exists
[junit4:junit4] 2> 764247 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41WithOrds_0.tii because it already exists
[junit4:junit4] 2> 764247 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
[junit4:junit4] 2> 764247 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4:junit4] 2> 764247 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4:junit4] 2> 764247 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvm because it already exists
[junit4:junit4] 2> 764249 T3083 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_Lucene41WithOrds_0.tii&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4:junit4] 2> 764250 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4:junit4] 2> 764250 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41WithOrds_0.doc because it already exists
[junit4:junit4] 2> 764251 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvd because it already exists
[junit4:junit4] 2> 764252 T3084 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4:junit4] 2> 764255 T3081 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_Lucene41WithOrds_0.tib&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=1
[junit4:junit4] 2> 764255 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4:junit4] 2> 764257 T3082 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4:junit4] 2> 764259 T3083 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4:junit4] 2> 764260 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
[junit4:junit4] 2> 764262 T3084 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4:junit4] 2> 764262 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
[junit4:junit4] 2> 764263 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4:junit4] 2> 764263 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41WithOrds_0.tii because it already exists
[junit4:junit4] 2> 764264 T3081 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4:junit4] 2> 764265 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41WithOrds_0.tib because it already exists
[junit4:junit4] 2> 764265 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4:junit4] 2> 764265 T3097 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4:junit4] 2> 764267 T3082 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_4&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4:junit4] 2> 764268 T3097 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 764268 T3097 oash.SnapPuller.downloadConfFiles Starting download of configuration files from master: [{name=schema.xml, checksum=1505963717, size=1634}]
[junit4:junit4] 2> 764271 T3083 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filecontent&checksum=true&wt=filestream&cf=schema.xml&qt=/replication&generation=4} status=0 QTime=0
[junit4:junit4] 2> 764274 T3097 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4:junit4] 2> 764274 T3097 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 764275 T3097 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 764276 T3097 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 764278 T3097 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=3
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_3,generation=3}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_4,generation=4}
[junit4:junit4] 2> 764278 T3097 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4:junit4] 2> 764279 T3097 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 764279 T3097 oash.SnapPuller.fetchLatestIndex Configuration files are modified, core will be reloaded
[junit4:junit4] 2> 764280 T3099 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1
[junit4:junit4] 2> 764280 T3099 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/'
[junit4:junit4] 2> 764281 T3097 oass.SolrIndexSearcher.<init> Opening Searcher@29fd37 main
[junit4:junit4] 2> 764281 T3096 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@29fd37 main{StandardDirectoryReader(segments_4:8:nrt _0(5.0):C71 _1(5.0):C190 _2(5.0):C87)}
[junit4:junit4] 2> 764282 T3097 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650513 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650513;done=true>>]
[junit4:junit4] 2> 764282 T3097 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650513
[junit4:junit4] 2> 764282 T3069 C1907 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:58865/solr/replication&command=fetchindex&wait=true} status=0 QTime=46
[junit4:junit4] 2> 764285 T3072 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 764319 T3099 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 764354 T3099 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 764354 T3099 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 764357 T3099 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 764368 T3099 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 764369 T3099 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/
[junit4:junit4] 2> 764369 T3099 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4] 2> 764369 T3099 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045649381
[junit4:junit4] 2> 764370 T3099 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 764370 T3099 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 764370 T3099 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 764371 T3099 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 764371 T3099 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 764371 T3099 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 764374 T3099 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 764376 T3099 oass.SolrIndexSearcher.<init> Opening Searcher@1c887b2 main
[junit4:junit4] 2> 764376 T3099 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 764376 T3099 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 764377 T3099 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 764377 T3099 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 764377 T3100 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c887b2 main{StandardDirectoryReader(segments_4:8:nrt _0(5.0):C71 _1(5.0):C190 _2(5.0):C87)}
[junit4:junit4] 2> 764377 T3099 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 764377 T3099 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4] 2> 764379 T3099 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=3
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_3,generation=3}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_4,generation=4}
[junit4:junit4] 2> 764379 T3099 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4:junit4] 2> 764379 T3099 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 764380 T3099 oass.SolrIndexSearcher.<init> Opening Searcher@8e0c12 main
[junit4:junit4] 2> 764380 T3099 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4] 2> 764380 T3099 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@f7221f
[junit4:junit4] 2> 764380 T3100 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8e0c12 main{StandardDirectoryReader(segments_4:8:nrt _0(5.0):C71 _1(5.0):C190 _2(5.0):C87)}
[junit4:junit4] 2> 764381 T3099 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:junit4] 2> 764381 T3099 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 764487 T3070 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> ASYNC NEW_CORE C1908 name=collection1 org.apache.solr.core.SolrCore@1bab1a0
[junit4:junit4] 2> 764494 T3069 C1908 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=348 status=0 QTime=1
[junit4:junit4] 2> 764497 T3084 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 764499 T3082 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 764501 T3072 C1908 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 764503 T3083 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=1
[junit4:junit4] 2> 764504 T3071 C1908 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 764507 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[348]} 0 0
[junit4:junit4] 2> 764509 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[349]} 0 0
[junit4:junit4] 2> 764511 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[350]} 0 1
[junit4:junit4] 2> 764512 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[351]} 0 0
[junit4:junit4] 2> 764514 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[352]} 0 0
[junit4:junit4] 2> 764516 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[353]} 0 0
[junit4:junit4] 2> 764517 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[354]} 0 0
[junit4:junit4] 2> 764519 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[355]} 0 0
[junit4:junit4] 2> 764521 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[356]} 0 0
[junit4:junit4] 2> 764523 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[357]} 0 0
[junit4:junit4] 2> 764524 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[358]} 0 0
[junit4:junit4] 2> 764526 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[359]} 0 0
[junit4:junit4] 2> 764528 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[360]} 0 0
[junit4:junit4] 2> 764530 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[361]} 0 0
[junit4:junit4] 2> 764531 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[362]} 0 0
[junit4:junit4] 2> 764533 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[363]} 0 0
[junit4:junit4] 2> 764535 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[364]} 0 0
[junit4:junit4] 2> 764537 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[365]} 0 1
[junit4:junit4] 2> 764538 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[366]} 0 0
[junit4:junit4] 2> 764540 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[367]} 0 0
[junit4:junit4] 2> 764542 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[368]} 0 0
[junit4:junit4] 2> 764543 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[369]} 0 0
[junit4:junit4] 2> 764545 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[370]} 0 0
[junit4:junit4] 2> 764547 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[371]} 0 0
[junit4:junit4] 2> 764548 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[372]} 0 0
[junit4:junit4] 2> 764550 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[373]} 0 0
[junit4:junit4] 2> 764552 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[374]} 0 0
[junit4:junit4] 2> 764554 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[375]} 0 0
[junit4:junit4] 2> 764556 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[376]} 0 0
[junit4:junit4] 2> 764559 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[377]} 0 0
[junit4:junit4] 2> 764561 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[378]} 0 0
[junit4:junit4] 2> 764564 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[379]} 0 1
[junit4:junit4] 2> 764566 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[380]} 0 0
[junit4:junit4] 2> 764568 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[381]} 0 0
[junit4:junit4] 2> 764571 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[382]} 0 1
[junit4:junit4] 2> 764573 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[383]} 0 0
[junit4:junit4] 2> 764576 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[384]} 0 1
[junit4:junit4] 2> 764578 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[385]} 0 0
[junit4:junit4] 2> 764580 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[386]} 0 0
[junit4:junit4] 2> 764583 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[387]} 0 0
[junit4:junit4] 2> 764585 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[388]} 0 0
[junit4:junit4] 2> 764588 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[389]} 0 0
[junit4:junit4] 2> 764590 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[390]} 0 0
[junit4:junit4] 2> 764591 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[391]} 0 0
[junit4:junit4] 2> 764593 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[392]} 0 0
[junit4:junit4] 2> 764595 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[393]} 0 0
[junit4:junit4] 2> 764596 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[394]} 0 0
[junit4:junit4] 2> 764598 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[395]} 0 0
[junit4:junit4] 2> 764600 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[396]} 0 0
[junit4:junit4] 2> 764601 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[397]} 0 0
[junit4:junit4] 2> 764603 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[398]} 0 0
[junit4:junit4] 2> 764605 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[399]} 0 0
[junit4:junit4] 2> 764606 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[400]} 0 0
[junit4:junit4] 2> 764608 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[401]} 0 0
[junit4:junit4] 2> 764610 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[402]} 0 0
[junit4:junit4] 2> 764611 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[403]} 0 0
[junit4:junit4] 2> 764613 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[404]} 0 0
[junit4:junit4] 2> 764615 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[405]} 0 0
[junit4:junit4] 2> 764616 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[406]} 0 0
[junit4:junit4] 2> 764618 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[407]} 0 0
[junit4:junit4] 2> 764620 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[408]} 0 0
[junit4:junit4] 2> 764622 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[409]} 0 0
[junit4:junit4] 2> 764624 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[410]} 0 0
[junit4:junit4] 2> 764625 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[411]} 0 0
[junit4:junit4] 2> 764627 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[412]} 0 0
[junit4:junit4] 2> 764629 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[413]} 0 0
[junit4:junit4] 2> 764631 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[414]} 0 1
[junit4:junit4] 2> 764633 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[415]} 0 1
[junit4:junit4] 2> 764635 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[416]} 0 0
[junit4:junit4] 2> 764637 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[417]} 0 0
[junit4:junit4] 2> 764639 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[418]} 0 0
[junit4:junit4] 2> 764641 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[419]} 0 0
[junit4:junit4] 2> 764643 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[420]} 0 0
[junit4:junit4] 2> 764645 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[421]} 0 0
[junit4:junit4] 2> 764647 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[422]} 0 0
[junit4:junit4] 2> 764649 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[423]} 0 0
[junit4:junit4] 2> 764651 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[424]} 0 0
[junit4:junit4] 2> 764654 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[425]} 0 1
[junit4:junit4] 2> 764656 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[426]} 0 1
[junit4:junit4] 2> 764658 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[427]} 0 0
[junit4:junit4] 2> 764660 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[428]} 0 0
[junit4:junit4] 2> 764662 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[429]} 0 0
[junit4:junit4] 2> 764664 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[430]} 0 0
[junit4:junit4] 2> 764666 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[431]} 0 0
[junit4:junit4] 2> 764668 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[432]} 0 0
[junit4:junit4] 2> 764670 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[433]} 0 0
[junit4:junit4] 2> 764672 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[434]} 0 0
[junit4:junit4] 2> 764674 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[435]} 0 0
[junit4:junit4] 2> 764675 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[436]} 0 0
[junit4:junit4] 2> 764677 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[437]} 0 0
[junit4:junit4] 2> 764679 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[438]} 0 0
[junit4:junit4] 2> 764681 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[439]} 0 0
[junit4:junit4] 2> 764682 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[440]} 0 0
[junit4:junit4] 2> 764684 T3082 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[441]} 0 0
[junit4:junit4] 2> 764686 T3083 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[442]} 0 0
[junit4:junit4] 2> 764688 T3081 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[443]} 0 1
[junit4:junit4] 2> 764689 T3084 C1905 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 764692 T3084 C1905 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=4
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_3,generation=3}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_4,generation=4}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_5,generation=5}
[junit4:junit4] 2> 764693 T3084 C1905 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4:junit4] 2> 764694 T3084 C1905 oass.SolrIndexSearcher.<init> Opening Searcher@1f58a40 main
[junit4:junit4] 2> 764694 T3084 C1905 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 764694 T3086 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f58a40 main{StandardDirectoryReader(segments_5:10:nrt _0(5.0):C71 _1(5.0):C190 _2(5.0):C87 _3(5.0):C96)}
[junit4:junit4] 2> 764694 T3084 C1905 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> 764697 T3082 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=444 status=0 QTime=1
[junit4:junit4] 2> 764700 T3070 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 764701 T3101 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4] 2> 764701 T3101 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 764703 T3083 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 764703 T3101 oash.SnapPuller.fetchLatestIndex Master's generation: 5
[junit4:junit4] 2> 764703 T3101 oash.SnapPuller.fetchLatestIndex Slave's generation: 4
[junit4:junit4] 2> 764704 T3101 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 764706 T3081 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=5&version=2} status=0 QTime=1
[junit4:junit4] 2> 764706 T3101 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 37
[junit4:junit4] 2> 764707 T3101 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650979
[junit4:junit4] 2> 764707 T3101 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@95074c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@194172f) fullCopy=false
[junit4:junit4] 2> 764707 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _2.si because it already exists
[junit4:junit4] 2> 764707 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _2_Lucene41WithOrds_0.doc because it already exists
[junit4:junit4] 2> 764707 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41WithOrds_0.tib because it already exists
[junit4:junit4] 2> 764709 T3084 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_Lucene41WithOrds_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4:junit4] 2> 764710 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41WithOrds_0.doc because it already exists
[junit4:junit4] 2> 764711 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41WithOrds_0.tii because it already exists
[junit4:junit4] 2> 764712 T3082 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4:junit4] 2> 764715 T3083 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4:junit4] 2> 764716 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
[junit4:junit4] 2> 764717 T3081 C1905 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4:junit4] 2> ASYNC NEW_CORE C1909 name=collection1 org.apache.solr.core.SolrCore@19bf23b
[junit4:junit4] 2> 764752 T3084 C1909 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_Lucene41WithOrds_0.tib&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4:junit4] 2> 764753 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4:junit4] 2> 764755 T3082 C1909 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4:junit4] 2> 764756 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4:junit4] 2> 764758 T3083 C1909 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_Lucene41WithOrds_0.tii&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4:junit4] 2> 764759 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvm because it already exists
[junit4:junit4] 2> 764759 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _2_Lucene41WithOrds_0.tii because it already exists
[junit4:junit4] 2> 764759 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4:junit4] 2> 764760 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41WithOrds_0.doc because it already exists
[junit4:junit4] 2> 764760 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvd because it already exists
[junit4:junit4] 2> 764760 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdt because it already exists
[junit4:junit4] 2> 764760 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _2_Lucene41WithOrds_0.tib because it already exists
[junit4:junit4] 2> 764760 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4:junit4] 2> 764760 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdx because it already exists
[junit4:junit4] 2> 764761 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fnm because it already exists
[junit4:junit4] 2> 764763 T3081 C1909 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4:junit4] 2> 764764 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
[junit4:junit4] 2> 764764 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _2.nvm because it already exists
[junit4:junit4] 2> 764764 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
[junit4:junit4] 2> 764764 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4:junit4] 2> 764764 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41WithOrds_0.tii because it already exists
[junit4:junit4] 2> 764765 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _2.nvd because it already exists
[junit4:junit4] 2> 764765 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41WithOrds_0.tib because it already exists
[junit4:junit4] 2> 764765 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4:junit4] 2> 764767 T3084 C1909 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4:junit4] 2> 764771 T3082 C1909 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_5&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4:junit4] 2> 764772 T3101 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4:junit4] 2> 764772 T3101 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 764773 T3101 oash.SnapPuller.downloadConfFiles Starting download of configuration files from master: [{name=schema.xml, checksum=265618607, size=1508}]
[junit4:junit4] 2> 764775 T3083 C1909 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filecontent&checksum=true&wt=filestream&cf=schema.xml&qt=/replication&generation=5} status=0 QTime=0
[junit4:junit4] 2> 764798 T3101 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4:junit4] 2> 764798 T3101 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 764807 T3101 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 764808 T3101 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 764810 T3101 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=4
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_3,generation=3}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_4,generation=4}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_5,generation=5}
[junit4:junit4] 2> 764811 T3101 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4:junit4] 2> 764811 T3101 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 764811 T3101 oash.SnapPuller.fetchLatestIndex Configuration files are modified, core will be reloaded
[junit4:junit4] 2> 764812 T3103 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1
[junit4:junit4] 2> 764812 T3103 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/'
[junit4:junit4] 2> 764813 T3101 oass.SolrIndexSearcher.<init> Opening Searcher@1820849 main
[junit4:junit4] 2> 764814 T3100 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1820849 main{StandardDirectoryReader(segments_5:10:nrt _0(5.0):C71 _1(5.0):C190 _2(5.0):C87 _3(5.0):C96)}
[junit4:junit4] 2> 764814 T3101 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650979 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650979;done=true>>]
[junit4:junit4] 2> 764814 T3101 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045650979
[junit4:junit4] 2> ASYNC NEW_CORE C1910 name=collection1 org.apache.solr.core.SolrCore@1bab1a0
[junit4:junit4] 2> 764814 T3072 C1910 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:58865/solr/replication&command=fetchindex&wait=true} status=0 QTime=113
[junit4:junit4] 2> 764817 T3071 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 764838 T3103 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 764866 T3103 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 764866 T3103 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 764868 T3103 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 764878 T3103 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 764879 T3103 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/
[junit4:junit4] 2> 764879 T3103 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4] 2> 764879 T3103 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622208577/slave/collection1/data/index.20130701045649381
[junit4:junit4] 2> 764880 T3103 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 764880 T3103 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 764880 T3103 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 764880 T3103 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 764881 T3103 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 764881 T3103 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 764883 T3103 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 764885 T3103 oass.SolrIndexSearcher.<init> Opening Searcher@b3eb14 main
[junit4:junit4] 2> 764886 T3103 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 764886 T3103 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 764886 T3103 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 764886 T3103 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 764886 T3104 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b3eb14 main{StandardDirectoryReader(segments_5:10:nrt _0(5.0):C71 _1(5.0):C190 _2(5.0):C87 _3(5.0):C96)}
[junit4:junit4] 2> 764886 T3103 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 764887 T3103 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4] 2> 764888 T3103 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=4
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_3,generation=3}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_4,generation=4}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1122553 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12da3a4),segFN=segments_5,generation=5}
[junit4:junit4] 2> 764889 T3103 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4:junit4] 2> 764889 T3103 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 764890 T3103 oass.SolrIndexSearcher.<init> Opening Searcher@312b57 main
[junit4:junit4] 2> 764890 T3103 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4] 2> 764890 T3103 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1bab1a0
[junit4:junit4] 2> 764890 T3104 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@312b57 main{StandardDirectoryReader(segments_5:10:nrt _0(5.0):C71 _1(5.0):C190 _2(5.0):C87 _3(5.0):C96)}
[junit4:junit4] 2> 764890 T3103 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:junit4] 2> 764891 T3103 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 765020 T3069 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> ASYNC NEW_CORE C1911 name=collection1 org.apache.solr.core.SolrCore@148e17
[junit4:junit4] 2> 765027 T3070 C1911 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=444 status=0 QTime=2
[junit4:junit4] 2> 765031 T3081 C1909 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 765033 T3082 C1909 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 765036 T3072 C1911 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=1
[junit4:junit4] 2> 765038 T3083 C1909 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=1
[junit4:junit4] 2> 765040 T3071 C1911 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4:junit4] 2> 765042 T3084 C1909 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[444]} 0 1
[junit4:junit4] 2> 765044 T3081 C1909 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[445]} 0 0
[junit4:junit4] 2> 765046 T3082 C1909 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[446]} 0 1
[junit4:junit4] 2> 765048 T3083 C1909 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[447]} 0 0
[junit4:junit4] 2> 765050 T3084 C1909 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[448]} 0 1
[junit4:junit4] 2> 765052 T3081 C1909 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[449]} 0 1
[junit4:junit4] 2> 765053 T3082 C1909 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 765056 T3082 C1909 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=5
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_3,generation=3}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_4,generation=4}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_5,generation=5}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1172f28 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ddb85),segFN=segments_6,generation=6}
[junit4:junit4] 2> 765056 T3082 C1909 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4:junit4] 2> 765057 T3082 C1909 oass.SolrIndexSearcher.<init> Opening Searcher@2a08e7 main
[junit4:junit4] 2> 765057 T3082 C1909 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 765057 T3086 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2a08e7 main{StandardDirectoryReader(segments_6:12:nrt _0(5.0):C71 _1(5.0):C190 _2(5.0):C87 _3(5.0):C96 _4(5.0):C6)}
[junit4:junit4] 2> 765058 T3082 C1909 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=t
[...truncated too long message...]
status=0 QTime=0
[junit4:junit4] 2> 825724 T3670 oash.SnapShooter.createSnapshot Creating backup snapshot...
[junit4:junit4] 2> 825724 T3661 C1982 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=backup} status=0 QTime=0
[junit4:junit4] 2> 825729 T3651 oash.SnapPuller.fetchLatestIndex ERROR Master at: http://127.0.0.1:38073/solr is not available. Index fetch failed. Exception: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:38073/solr
[junit4:junit4] 2> 825926 T3660 C1982 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details} status=0 QTime=0
[junit4:junit4] 2> 825930 T3038 oas.SolrTestCaseJ4.tearDown ###Ending doTestBackup
[junit4:junit4] 2> 825951 T3038 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=25298719
[junit4:junit4] 2> 825952 T3038 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@15c5c21
[junit4:junit4] 2> 825952 T3038 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=492,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4] 2> 825953 T3038 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 825953 T3038 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 825954 T3038 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 825956 T3038 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 825957 T3038 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 825958 T3038 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269282/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269282/master/collection1/data;done=false>>]
[junit4:junit4] 2> 825959 T3038 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269282/master/collection1/data
[junit4:junit4] 2> 825959 T3038 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269282/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269282/master/collection1/data/index;done=false>>]
[junit4:junit4] 2> 825960 T3038 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269282/master/collection1/data/index
[junit4:junit4] 2> 825961 T3038 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4] 2> 826034 T3038 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=25875638
[junit4:junit4] 2> 826034 T3038 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@463f3b
[junit4:junit4] 2> 826035 T3038 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:junit4] 2> 826035 T3038 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 826036 T3038 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 826036 T3038 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 826037 T3038 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 826037 T3038 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 826037 T3038 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269440/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269440/slave/collection1/data;done=false>>]
[junit4:junit4] 2> 826038 T3038 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269440/slave/collection1/data
[junit4:junit4] 2> 826038 T3038 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269440/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269440/slave/collection1/data/index;done=false>>]
[junit4:junit4] 2> 826039 T3038 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1372622269440/slave/collection1/data/index
[junit4:junit4] 2> 826039 T3038 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4] 2> 826101 T3038 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {newname=PostingsFormat(name=Lucene41WithOrds), id=PostingsFormat(name=Lucene41WithOrds), name=PostingsFormat(name=Lucene41WithOrds)}, docValues:{}, sim=DefaultSimilarity, locale=en_IN, timezone=Asia/Irkutsk
[junit4:junit4] 2> NOTE: Linux 3.2.0-48-generic i386/Oracle Corporation 1.7.0_25 (32-bit)/cpus=8,threads=1,free=353245960,total=536870912
[junit4:junit4] 2> NOTE: All tests run in this JVM: [SyncSliceTest, ResponseLogComponentTest, BasicFunctionalityTest, DistributedQueryElevationComponentTest, DocumentBuilderTest, BlockDirectoryTest, LukeRequestHandlerTest, TestStressRecovery, TermVectorComponentTest, PrimitiveFieldTypeTest, TestSolrDeletionPolicy2, PrimUtilsTest, TestPluginEnable, DocValuesTest, TestAddFieldRealTimeGet, TestSurroundQueryParser, TestPropInjectDefaults, DirectUpdateHandlerOptimizeTest, MBeansHandlerTest, TestSolrDeletionPolicy1, AssignTest, ZkCLITest, FastVectorHighlighterTest, PreAnalyzedFieldTest, TestRemoteStreaming, TestFuzzyAnalyzedSuggestions, TestJoin, BasicHdfsTest, TermsComponentTest, TestIBSimilarityFactory, SimpleFacetsTest, TestFieldTypeResource, MinimalSchemaTest, ParsingFieldUpdateProcessorsTest, TestSerializedLuceneMatchVersion, BadCopyFieldTest, UUIDFieldTest, TestStressVersions, JsonLoaderTest, TestCoreContainer, TestValueSourceCache, PeerSyncTest, PolyFieldTest, ZkControllerTest, DateFieldTest, TestPerFieldSimilarity, PreAnalyzedUpdateProcessorTest, TestTrie, TestRandomDVFaceting, SearchHandlerTest, SuggesterFSTTest, TestDefaultSearchFieldResource, TestLFUCache, CSVRequestHandlerTest, DistributedTermsComponentTest, TestPhraseSuggestions, TestXIncludeConfig, AlternateDirectoryTest, SchemaVersionSpecificBehaviorTest, TestDocSet, ChaosMonkeyNothingIsSafeTest, ResourceLoaderTest, StatelessScriptUpdateProcessorFactoryTest, TestDynamicFieldResource, AnalysisAfterCoreReloadTest, TestSchemaNameResource, TestFunctionQuery, TestRealTimeGet, BlockCacheTest, BinaryUpdateRequestHandlerTest, TestMaxScoreQueryParser, CircularListTest, BasicDistributedZkTest, TestPseudoReturnFields, OpenCloseCoreStressTest, OverseerTest, ShardRoutingTest, RecoveryZkTest, TestReplicationHandler]
[junit4:junit4] Completed on J0 in 64.00s, 13 tests, 1 failure <<< FAILURES!
[...truncated 449 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:386: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:366: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:190: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:443: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1245: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:889: There were test failures: 312 suites, 1316 tests, 1 failure, 20 ignored (13 assumptions)
Total time: 41 minutes 23 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_25 -server -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure