lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.6.0_45) - Build # 2742 - Still Failing!
Date Sun, 28 Apr 2013 09:08:20 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/2742/
Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseParallelGC

1 tests failed.
REGRESSION:  org.apache.solr.handler.TestReplicationHandler.doTestStressReplication

Error Message:
timed out waiting for collection1 startAt time to exceed: Sun Apr 28 04:32:41 AST 2013

Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Sun Apr 28 04:32:41 AST 2013
	at __randomizedtesting.SeedInfo.seed([E00EBF2F6915D411:3BA5BFE96C3DBDA2]: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:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	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:662)




Build Log:
[...truncated 8441 lines...]
[junit4:junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:29.991; org.apache.solr.SolrTestCaseJ4; ###Starting testEmptyCommits
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.003; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.008; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:57512
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.008; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.009; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.009; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.009; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.009; org.apache.solr.core.CoreContainer; New CoreContainer 220931271
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.010; org.apache.solr.core.CoreContainer$Initializer; no solr.xml found. using default old-style solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.010; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.010; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.118; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.118; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.119; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.119; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.119; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.120; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.120; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.120; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.121; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.121; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.128; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.133; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.134; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.187; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.258; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.259; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.262; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.286; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.288; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.288; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\, dataDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.288; org.apache.solr.core.SolrCore; JMX monitoring not detected for core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.288; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.290; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.290; org.apache.solr.core.SolrCore; New index directory detected: old=null new=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\data\index/
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:30.290; org.apache.solr.core.SolrCore; [collection1] Solr index directory '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\data\index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.290; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.291; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.291; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.292; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.293; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.293; org.apache.solr.core.RequestHandlers; created defaults: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.293; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.293; org.apache.solr.core.RequestHandlers; created lazy: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.294; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.300; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.318; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@61dee8db main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.319; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.319; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.320; org.apache.solr.handler.ReplicationHandler; Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.320; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for  10000
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.320; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.321; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.327; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.327; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.337; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@61dee8db main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.346; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.350; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:57515
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.351; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.351; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.352; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.352; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.352; org.apache.solr.core.CoreContainer; New CoreContainer 1577638546
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.353; org.apache.solr.core.CoreContainer$Initializer; no solr.xml found. using default old-style solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.353; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.353; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.444; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.445; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.445; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.446; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.446; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.446; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.446; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.447; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.448; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.448; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.452; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.458; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.459; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.509; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.571; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.572; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.575; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.597; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.599; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.599; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\, dataDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.599; org.apache.solr.core.SolrCore; JMX monitoring not detected for core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.599; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.600; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.600; org.apache.solr.core.SolrCore; New index directory detected: old=null new=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index/
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:30.600; org.apache.solr.core.SolrCore; [collection1] Solr index directory '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.601; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.603; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.604; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.606; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.606; org.apache.solr.core.RequestHandlers; created defaults: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.606; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.607; org.apache.solr.core.RequestHandlers; created lazy: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.607; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.607; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.609; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.613; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@112cff56 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.613; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.614; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.618; org.apache.solr.handler.SnapPuller; Poll Scheduled at an interval of 1000ms
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.618; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.618; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@112cff56 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.619; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.619; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.620; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.635; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.640; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.641; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.641; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 2
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.643; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.644; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_1,generation=1}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_2,generation=2}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.645; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 2
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.646; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@417ffb28 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.646; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.646; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@417ffb28 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.647; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 4
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:30.691; org.apache.solr.handler.SnapPuller; 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.691; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.693; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.693; org.apache.solr.handler.SnapPuller; Master's generation: 2
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.693; org.apache.solr.handler.SnapPuller; Slave's generation: 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.693; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.705; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=9 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.706; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 10
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.706; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230706
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.707; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@2ce038b6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1c2ce9f9) fullCopy=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.709; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:30.712; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_0_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.715; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.718; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_0.frq&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.721; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:30.724; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:30.726; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_0_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.730; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:30.735; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.738; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:30.739; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.742; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.743; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.744; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_1,generation=1}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_2,generation=2}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.745; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 2
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.745; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.746; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@2f880917 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.747; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@2f880917 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.748; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230706 [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230706;done=true>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.748; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230706
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.749; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230706
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.749; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:57512/solr/replication&command=fetchindex&wait=true} status=0 QTime=59 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.784; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty1&wt=javabin&version=2} hits=1 status=0 QTime=20 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.789; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.792; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.798; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.800; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=5 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.802; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.805; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.808; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.809; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_3,generation=3}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.810; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 3
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.811; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@12dace3b main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.811; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.811; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@12dace3b main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.812; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 4
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:30.816; org.apache.solr.handler.SnapPuller; 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.817; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.822; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.823; org.apache.solr.handler.SnapPuller; Master's generation: 3
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.823; org.apache.solr.handler.SnapPuller; Slave's generation: 2
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.824; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.827; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=3&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.829; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 10
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.829; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230829
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.830; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@2bdf7750 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3fec7107) fullCopy=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.830; org.apache.solr.handler.SnapPuller; Skipping download for _0.fnm because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.831; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfe because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.831; org.apache.solr.handler.SnapPuller; Skipping download for _0.tim because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.832; org.apache.solr.handler.SnapPuller; Skipping download for _0.frq because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.832; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdx because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.832; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfs because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.832; org.apache.solr.handler.SnapPuller; Skipping download for _0.si because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.833; org.apache.solr.handler.SnapPuller; Skipping download for _0.tip because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.837; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:30.838; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdt because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.839; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.844; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.844; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.845; org.apache.solr.update.DefaultSolrCoreState; Closing old IndexWriter... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.849; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_3,generation=3}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.850; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 3
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.850; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.851; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1c6b7657 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.852; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@1c6b7657 main{StandardDirectoryReader(segments_3:3:nrt _0(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.853; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230829 [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230829;done=true>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.853; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230829
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.854; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230829
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.855; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:57512/solr/replication&command=fetchindex&wait=true} status=0 QTime=40 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.861; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 2
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.865; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.868; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_3,generation=3}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_4,generation=4}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.869; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 4
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.871; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@42b113b8 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.872; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.872; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@42b113b8 main{StandardDirectoryReader(segments_4:5:nrt _0(4.4):C1 _1(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.874; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 10
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:30.878; org.apache.solr.handler.SnapPuller; 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.878; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.882; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.883; org.apache.solr.handler.SnapPuller; Master's generation: 4
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.883; org.apache.solr.handler.SnapPuller; Slave's generation: 3
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.883; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.889; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=4&version=2} status=0 QTime=3 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.891; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 19
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.891; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230891
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.892; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@3cc48550 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@64157d2) fullCopy=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.896; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.898; org.apache.solr.handler.SnapPuller; Skipping download for _0.fnm because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.901; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1.frq&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.903; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfs because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.907; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.912; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.917; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.923; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.927; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.928; org.apache.solr.handler.SnapPuller; Skipping download for _0.frq because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.928; org.apache.solr.handler.SnapPuller; Skipping download for _0.tim because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.929; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfe because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.930; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdx because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.930; org.apache.solr.handler.SnapPuller; Skipping download for _0.si because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.930; org.apache.solr.handler.SnapPuller; Skipping download for _0.tip because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.933; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.934; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdt because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.936; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.940; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:30.942; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.947; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.947; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.947; org.apache.solr.update.DefaultSolrCoreState; Closing old IndexWriter... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.951; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=3
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_3,generation=3}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_4,generation=4}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.952; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 4
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.952; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.954; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@3ff96afb main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.955; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@3ff96afb main{StandardDirectoryReader(segments_4:5:nrt _0(4.4):C1 _1(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.956; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230891 [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230891;done=true>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.956; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230891
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.956; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043230891
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.958; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:57512/solr/replication&command=fetchindex&wait=true} status=0 QTime=81 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.963; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty2&wt=javabin&version=2} hits=1 status=0 QTime=2 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.967; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.973; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.980; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.982; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=6 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.985; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.990; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.994; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[3]} 0 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:30.997; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.001; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=4
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_3,generation=3}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_4,generation=4}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_5,generation=5}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.002; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.003; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.004; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@696f551d realtime
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.004; org.apache.solr.handler.SnapPuller; Slave in sync with master.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.005; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.007; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={openSearcher=false&commit=true&wt=javabin&version=2} {commit=} 0 10
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:31.010; org.apache.solr.handler.SnapPuller; 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.010; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.014; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.015; org.apache.solr.handler.SnapPuller; Master's generation: 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.015; org.apache.solr.handler.SnapPuller; Slave's generation: 4
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.016; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.018; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=5&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.020; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 28
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.021; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043231021
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.022; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@33f46cf7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f3930b4) fullCopy=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.027; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.028; org.apache.solr.handler.SnapPuller; Skipping download for _1.frq because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.029; org.apache.solr.handler.SnapPuller; Skipping download for _1.fnm because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.032; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.036; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.041; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.042; org.apache.solr.handler.SnapPuller; Skipping download for _0.si because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.042; org.apache.solr.handler.SnapPuller; Skipping download for _1.tip because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.042; org.apache.solr.handler.SnapPuller; Skipping download for _1.tim because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.043; org.apache.solr.handler.SnapPuller; Skipping download for _1_nrm.cfs because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.043; org.apache.solr.handler.SnapPuller; Skipping download for _0.fnm because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.047; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.052; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2.frq&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.054; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfs because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.058; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.058; org.apache.solr.handler.SnapPuller; Skipping download for _1_nrm.cfe because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.062; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.067; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.069; org.apache.solr.handler.SnapPuller; Skipping download for _1.fdx because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.069; org.apache.solr.handler.SnapPuller; Skipping download for _1.fdt because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.070; org.apache.solr.handler.SnapPuller; Skipping download for _1.si because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.071; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfe because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.071; org.apache.solr.handler.SnapPuller; Skipping download for _0.tim because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.071; org.apache.solr.handler.SnapPuller; Skipping download for _0.frq because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.072; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdx because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.076; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=segments_5&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.077; org.apache.solr.handler.SnapPuller; Skipping download for _0.tip because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.077; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdt because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.077; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.082; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.082; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.083; org.apache.solr.update.DefaultSolrCoreState; Closing old IndexWriter... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.087; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=3
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_4,generation=4}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_5,generation=5}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.087; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.087; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.088; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@a10a9cd main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.088; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@a10a9cd main{StandardDirectoryReader(segments_5:7:nrt _0(4.4):C1 _1(4.4):C1 _2(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.089; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043231021 [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043231021;done=true>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.089; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043231021
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.089; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043231021
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.090; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:57512/solr/replication&command=fetchindex&wait=true} status=0 QTime=81 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.094; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty3&wt=javabin&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.097; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty3&wt=javabin&version=2} hits=1 status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.100; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[4]} 0 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.103; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.106; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=5
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_3,generation=3}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_4,generation=4}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_5,generation=5}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@831ebd9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7b16ea43),segFN=segments_6,generation=6}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.106; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 6
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.107; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@20b13914 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.108; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.108; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@20b13914 main{StandardDirectoryReader(segments_6:9:nrt _0(4.4):C1 _1(4.4):C1 _2(4.4):C1 _3(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.109; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 6
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:31.111; org.apache.solr.handler.SnapPuller; 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.111; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.113; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.114; org.apache.solr.handler.SnapPuller; Master's generation: 6
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.114; org.apache.solr.handler.SnapPuller; Slave's generation: 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.114; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.117; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=6&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.117; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 37
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.118; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043231118
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.118; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@2e92a648 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b0244c) fullCopy=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.118; org.apache.solr.handler.SnapPuller; Skipping download for _2.si because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.121; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_3_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=6} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.124; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_3.frq&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=6} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.126; org.apache.solr.handler.SnapPuller; Skipping download for _1.frq because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.128; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_3.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=6} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.131; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_3.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=6} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.134; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_3.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=6} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.136; org.apache.solr.handler.SnapPuller; Skipping download for _1.fnm because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.136; org.apache.solr.handler.SnapPuller; Skipping download for _2.tim because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.136; org.apache.solr.handler.SnapPuller; Skipping download for _2_nrm.cfe because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.137; org.apache.solr.handler.SnapPuller; Skipping download for _2_nrm.cfs because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.137; org.apache.solr.handler.SnapPuller; Skipping download for _0.si because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.137; org.apache.solr.handler.SnapPuller; Skipping download for _1.tip because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.138; org.apache.solr.handler.SnapPuller; Skipping download for _1.tim because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.138; org.apache.solr.handler.SnapPuller; Skipping download for _1_nrm.cfs because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.139; org.apache.solr.handler.SnapPuller; Skipping download for _0.fnm because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.139; org.apache.solr.handler.SnapPuller; Skipping download for _2.fdt because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.140; org.apache.solr.handler.SnapPuller; Skipping download for _2.frq because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.140; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfs because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.140; org.apache.solr.handler.SnapPuller; Skipping download for _2.fdx because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.140; org.apache.solr.handler.SnapPuller; Skipping download for _1_nrm.cfe because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.140; org.apache.solr.handler.SnapPuller; Skipping download for _2.fnm because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.143; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_3.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=6} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.145; org.apache.solr.handler.SnapPuller; Skipping download for _2.tip because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.145; org.apache.solr.handler.SnapPuller; Skipping download for _1.fdx because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.148; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_3_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=6} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.150; org.apache.solr.handler.SnapPuller; Skipping download for _1.fdt because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.150; org.apache.solr.handler.SnapPuller; Skipping download for _1.si because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.150; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfe because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.151; org.apache.solr.handler.SnapPuller; Skipping download for _0.tim because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.151; org.apache.solr.handler.SnapPuller; Skipping download for _0.frq because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.152; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdx because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.155; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_3.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=6} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.161; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_3.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=6} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.166; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=segments_6&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=6} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.178; org.apache.solr.handler.SnapPuller; Skipping download for _0.tip because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.179; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdt because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.179; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.183; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.183; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.184; org.apache.solr.update.DefaultSolrCoreState; Closing old IndexWriter... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.243; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=4
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_4,generation=4}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_5,generation=5}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@38e2a040 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34806f42),segFN=segments_6,generation=6}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.245; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 6
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.246; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.250; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@3eeba269 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.251; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@3eeba269 main{StandardDirectoryReader(segments_6:9:nrt _0(4.4):C1 _1(4.4):C1 _2(4.4):C1 _3(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.252; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043231118 [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043231118;done=true>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.252; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043231118
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.254; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index.20130428043231118
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.255; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:57512/solr/replication&command=fetchindex&wait=true} status=0 QTime=145 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.263; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:(empty1+empty2+empty3+empty4)&wt=javabin&version=2} hits=4 status=0 QTime=4 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.270; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:(empty1+empty2+empty3+empty4)&wt=javabin&version=2} hits=4 status=0 QTime=4 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.274; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.280; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.288; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.291; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=7 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.297; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.301; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.302; org.apache.solr.SolrTestCaseJ4; ###Ending testEmptyCommits
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.316; org.apache.solr.core.CoreContainer; Shutting down CoreContainer instance=220931271
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.319; org.apache.solr.core.SolrCore; [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@6c1fa59f
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.320; org.apache.solr.update.DirectUpdateHandler2; closing DirectUpdateHandler2{commits=5,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=4,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.321; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.322; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.323; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.325; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.326; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.327; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\data\index [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\data\index;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.327; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.327; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\data\ [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\data\;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.328; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137949992\master\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.328; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.396; org.apache.solr.core.CoreContainer; Shutting down CoreContainer instance=1577638546
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.398; org.apache.solr.core.SolrCore; [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@584ced04
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.399; org.apache.solr.update.DirectUpdateHandler2; 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]   1> INFO  - 2013-04-28 08:32:31.400; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.402; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.403; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.407; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.458; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.460; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\ [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.461; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.462; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.463; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137950330\slave\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.464; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.548; org.apache.solr.SolrTestCaseJ4; ###Starting doTestDetails
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.560; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.564; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:57522
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.565; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.565; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.565; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.566; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.566; org.apache.solr.core.CoreContainer; New CoreContainer 1831521332
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.567; org.apache.solr.core.CoreContainer$Initializer; no solr.xml found. using default old-style solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.568; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.568; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.700; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.701; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.701; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.702; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.702; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.702; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.703; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.703; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.703; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.703; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.712; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.719; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.721; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.778; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.851; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.852; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.856; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.884; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.887; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.887; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\, dataDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.887; org.apache.solr.core.SolrCore; JMX monitoring not detected for core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.888; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.888; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.888; org.apache.solr.core.SolrCore; New index directory detected: old=null new=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\data\index/
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:31.889; org.apache.solr.core.SolrCore; [collection1] Solr index directory '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\data\index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.889; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.890; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@389ed39 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@21b7e734),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.890; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.891; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.891; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.891; org.apache.solr.core.RequestHandlers; created defaults: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.891; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.891; org.apache.solr.core.RequestHandlers; created lazy: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.891; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.898; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.902; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@45873320 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.902; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.902; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.903; org.apache.solr.handler.ReplicationHandler; Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.903; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for  10000
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.903; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.903; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@45873320 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.905; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.905; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.906; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.928; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.931; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:57525
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.931; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.932; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.932; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.933; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.933; org.apache.solr.core.CoreContainer; New CoreContainer 1850369317
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.933; org.apache.solr.core.CoreContainer$Initializer; no solr.xml found. using default old-style solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.934; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:31.934; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.043; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.043; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.044; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.044; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.044; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.045; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.045; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.045; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.046; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.046; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.050; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.056; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.058; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.126; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.221; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.222; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.225; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.252; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.254; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.254; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\, dataDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.254; org.apache.solr.core.SolrCore; JMX monitoring not detected for core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.254; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.262; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.262; org.apache.solr.core.SolrCore; New index directory detected: old=null new=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index/
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:32.263; org.apache.solr.core.SolrCore; [collection1] Solr index directory '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.263; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.265; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@683fbf43 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a348b27),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.265; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.266; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.266; org.apache.solr.core.RequestHandlers; created defaults: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.266; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.266; org.apache.solr.core.RequestHandlers; created lazy: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.266; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.267; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.269; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.273; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@628d28f1 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.273; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.273; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.275; org.apache.solr.handler.SnapPuller; Poll Scheduled at an interval of 1000ms
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.275; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.276; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.277; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.277; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.277; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@628d28f1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.300; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=2 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.302; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.314; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.315; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=4 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.319; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@389ed39 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@21b7e734),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.319; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.320; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0]} 0 2
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.323; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.324; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@389ed39 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@21b7e734),segFN=segments_1,generation=1}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@389ed39 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@21b7e734),segFN=segments_2,generation=2}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.324; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 2
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.325; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@77a7ed63 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.325; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.326; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@77a7ed63 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.326; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 3
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:32.329; org.apache.solr.handler.SnapPuller; 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.329; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.331; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.332; org.apache.solr.handler.SnapPuller; Master's generation: 2
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.332; org.apache.solr.handler.SnapPuller; Slave's generation: 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.332; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.336; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=2 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.337; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 10
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.337; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232337
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.337; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@49ab0137 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@cbff27f) fullCopy=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.351; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.355; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_0_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.358; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.361; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_0.frq&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.364; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.367; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.370; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_0_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.374; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.377; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.380; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.381; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.383; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.383; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.384; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@683fbf43 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a348b27),segFN=segments_1,generation=1}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@683fbf43 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a348b27),segFN=segments_2,generation=2}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.384; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 2
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.384; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.385; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@4643ac23 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.385; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@4643ac23 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.386; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232337 [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232337;done=true>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.386; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232337
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.386; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232337
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.387; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:57522/solr/replication&command=fetchindex&wait=true} status=0 QTime=59 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.392; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.393; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=2 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.396; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.399; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.403; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@389ed39 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@21b7e734),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@389ed39 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@21b7e734),segFN=segments_3,generation=3}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.403; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 3
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.405; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@4e124a9 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.405; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.405; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@4e124a9 main{StandardDirectoryReader(segments_3:5:nrt _0(4.4):C1 _1(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.406; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:32.407; org.apache.solr.handler.SnapPuller; 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.407; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.410; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.410; org.apache.solr.handler.SnapPuller; Master's generation: 3
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.410; org.apache.solr.handler.SnapPuller; Slave's generation: 2
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.410; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.412; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=3&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.413; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 19
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.414; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232414
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.414; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1261db2b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2dd4708d) fullCopy=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.417; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.418; org.apache.solr.handler.SnapPuller; Skipping download for _0.fnm because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.421; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1.frq&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.422; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfs because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.424; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.427; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.431; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.435; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.438; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.439; org.apache.solr.handler.SnapPuller; Skipping download for _0.frq because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.439; org.apache.solr.handler.SnapPuller; Skipping download for _0.tim because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.439; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfe because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.439; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdx because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.439; org.apache.solr.handler.SnapPuller; Skipping download for _0.si because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.439; org.apache.solr.handler.SnapPuller; Skipping download for _0.tip because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.442; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.443; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdt because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.445; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.448; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_1.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.449; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.451; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.451; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.452; org.apache.solr.update.DefaultSolrCoreState; Closing old IndexWriter... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.453; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@683fbf43 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a348b27),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@683fbf43 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a348b27),segFN=segments_3,generation=3}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.453; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 3
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.453; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.454; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@70f52030 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.455; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@70f52030 main{StandardDirectoryReader(segments_3:5:nrt _0(4.4):C1 _1(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.455; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232414 [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232414;done=true>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.455; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232414
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.455; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232414
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.456; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:57522/solr/replication&command=fetchindex&wait=true} status=0 QTime=49 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.462; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.463; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=3 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.466; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.469; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.471; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@389ed39 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@21b7e734),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@389ed39 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@21b7e734),segFN=segments_3,generation=3}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@389ed39 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@21b7e734),segFN=segments_4,generation=4}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.472; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 4
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.473; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@22d6d956 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.473; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.473; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@22d6d956 main{StandardDirectoryReader(segments_4:7:nrt _0(4.4):C1 _1(4.4):C1 _2(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.474; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:32.476; org.apache.solr.handler.SnapPuller; 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.476; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.478; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.479; org.apache.solr.handler.SnapPuller; Master's generation: 4
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.479; org.apache.solr.handler.SnapPuller; Slave's generation: 3
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.479; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.482; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=4&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.484; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 28
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.484; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232484
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.484; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@4a7c8353 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4645a73) fullCopy=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.486; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.487; org.apache.solr.handler.SnapPuller; Skipping download for _1.frq because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.488; org.apache.solr.handler.SnapPuller; Skipping download for _1.fnm because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.490; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.495; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.498; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.499; org.apache.solr.handler.SnapPuller; Skipping download for _0.si because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.500; org.apache.solr.handler.SnapPuller; Skipping download for _1.tip because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.500; org.apache.solr.handler.SnapPuller; Skipping download for _1.tim because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.500; org.apache.solr.handler.SnapPuller; Skipping download for _1_nrm.cfs because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.500; org.apache.solr.handler.SnapPuller; Skipping download for _0.fnm because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.502; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.507; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2.frq&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.508; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfs because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.512; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.513; org.apache.solr.handler.SnapPuller; Skipping download for _1_nrm.cfe because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.516; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.521; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={file=_2.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.537; org.apache.solr.handler.SnapPuller; Skipping download for _1.fdx because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.538; org.apache.solr.handler.SnapPuller; Skipping download for _1.fdt because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.538; org.apache.solr.handler.SnapPuller; Skipping download for _1.si because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.539; org.apache.solr.handler.SnapPuller; Skipping download for _0_nrm.cfe because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.539; org.apache.solr.handler.SnapPuller; Skipping download for _0.tim because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.539; org.apache.solr.handler.SnapPuller; Skipping download for _0.frq because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.540; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdx because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.540; org.apache.solr.handler.SnapPuller; Skipping download for _0.tip because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.541; org.apache.solr.handler.SnapPuller; Skipping download for _0.fdt because it already exists
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.545; org.apache.solr.core.SolrCore; [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]   1> INFO  - 2013-04-28 08:32:32.547; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.552; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.552; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.553; org.apache.solr.update.DefaultSolrCoreState; Closing old IndexWriter... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.556; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@683fbf43 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a348b27),segFN=segments_3,generation=3}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@683fbf43 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a348b27),segFN=segments_4,generation=4}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.556; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 4
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.557; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.558; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@31f9bcbc main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.567; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@31f9bcbc main{StandardDirectoryReader(segments_4:7:nrt _0(4.4):C1 _1(4.4):C1 _2(4.4):C1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.567; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232484 [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232484;done=true>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.568; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232484
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.568; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index.20130428043232484
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.568; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:57522/solr/replication&command=fetchindex&wait=true} status=0 QTime=93 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.581; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.584; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:57533
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.585; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.585; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.585; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.585; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.585; org.apache.solr.core.CoreContainer; New CoreContainer 779788499
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.587; org.apache.solr.core.CoreContainer$Initializer; no solr.xml found. using default old-style solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.587; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.588; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.692; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.693; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.693; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.693; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.693; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.694; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.694; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.694; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.695; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.695; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.699; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.705; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.707; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.765; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.831; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.832; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.835; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.858; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.860; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.860; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\, dataDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.860; org.apache.solr.core.SolrCore; JMX monitoring not detected for core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.860; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.861; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.861; org.apache.solr.core.SolrCore; New index directory detected: old=null new=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\data\index/
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:32.861; org.apache.solr.core.SolrCore; [collection1] Solr index directory '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\data\index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.862; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.863; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5725a42b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@65cb5512),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.863; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.864; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.864; org.apache.solr.core.RequestHandlers; created defaults: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.865; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.865; org.apache.solr.core.RequestHandlers; created lazy: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.865; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.865; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.868; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.871; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@732e9042 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.872; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.872; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:32.872; org.apache.solr.handler.SnapPuller; 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.872; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.872; org.apache.solr.handler.ReplicationHandler; Replication enabled for following config files: schema.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.872; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for  10000
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.874; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@732e9042 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.874; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.875; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.875; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.876; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.891; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.892; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=4 
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.909; org.apache.solr.core.CoreContainer; Shutting down CoreContainer instance=779788499
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.911; org.apache.solr.core.SolrCore; [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7080d6b4
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.911; org.apache.solr.update.DirectUpdateHandler2; 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]   1> INFO  - 2013-04-28 08:32:32.912; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.912; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.913; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.915; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.915; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.916; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\data\index [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\data\index;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.916; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.917; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\data\ [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\data\;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.918; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137952569\repeater\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.920; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:32.992; org.apache.solr.SolrTestCaseJ4; ###Ending doTestDetails
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.008; org.apache.http.impl.client.DefaultRequestDirector; I/O exception (java.net.SocketException) caught when processing request: Software caused connection abort: recv failed
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.011; org.apache.http.impl.client.DefaultRequestDirector; Retrying request
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.008; org.apache.solr.core.CoreContainer; Shutting down CoreContainer instance=1831521332
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.013; org.apache.solr.core.SolrCore; [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@6b543e44
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.013; org.apache.solr.update.DirectUpdateHandler2; closing DirectUpdateHandler2{commits=3,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=3,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.015; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.016; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.016; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.018; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.020; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.020; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\data\ [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\data\;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.021; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.022; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\data\index [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\data\index;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.023; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951549\master\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.024; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.093; org.apache.solr.core.CoreContainer; Shutting down CoreContainer instance=1850369317
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.095; org.apache.solr.core.SolrCore; [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@4b2b09f4
[junit4:junit4]   1> ERROR - 2013-04-28 08:32:33.967; org.apache.solr.handler.SnapPuller; Master at: http://127.0.0.1:57522/solr is not available. Index fetch failed. Exception: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:57522/solr
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.970; org.apache.solr.update.DirectUpdateHandler2; 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]   1> INFO  - 2013-04-28 08:32:33.972; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.972; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.973; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.975; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.976; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.977; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\ [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.978; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.979; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.980; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137951912\slave\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:33.981; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.069; org.apache.solr.SolrTestCaseJ4; ###Starting doTestStressReplication
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.081; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.084; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:57538
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.085; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.085; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.086; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.086; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.086; org.apache.solr.core.CoreContainer; New CoreContainer 1585183078
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.088; org.apache.solr.core.CoreContainer$Initializer; no solr.xml found. using default old-style solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.088; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.088; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.208; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.208; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.208; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.209; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.209; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.210; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.210; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.210; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.211; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.211; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.219; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.226; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.227; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.301; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.386; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.386; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.390; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.415; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.416; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.417; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\, dataDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.418; org.apache.solr.core.SolrCore; JMX monitoring not detected for core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.418; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.418; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.419; org.apache.solr.core.SolrCore; New index directory detected: old=null new=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\data\index/
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:34.419; org.apache.solr.core.SolrCore; [collection1] Solr index directory '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\data\index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.419; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.420; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@71b17530 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3560d2d1),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.420; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.421; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.422; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.423; org.apache.solr.core.RequestHandlers; created defaults: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.423; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.423; org.apache.solr.core.RequestHandlers; created lazy: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.423; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.429; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.433; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@77aa0759 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.433; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.433; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.433; org.apache.solr.handler.ReplicationHandler; Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.433; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for  10000
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.434; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.434; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@77aa0759 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.435; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.435; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.436; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.457; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.461; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:57541
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.462; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.462; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.462; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.462; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.462; org.apache.solr.core.CoreContainer; New CoreContainer 654212203
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.464; org.apache.solr.core.CoreContainer$Initializer; no solr.xml found. using default old-style solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.464; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.465; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.555; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.555; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.555; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.555; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.556; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.556; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.556; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.557; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.557; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.558; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.560; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.567; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.568; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.619; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.678; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.678; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.682; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.701; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.703; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.703; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\, dataDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.703; org.apache.solr.core.SolrCore; JMX monitoring not detected for core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.704; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.704; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.704; org.apache.solr.core.SolrCore; New index directory detected: old=null new=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\index/
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:34.704; org.apache.solr.core.SolrCore; [collection1] Solr index directory '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.705; org.apache.solr.core.CachingDirectoryFactory; return new directory for .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.706; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@34a63837 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@45c3d185),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.706; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.707; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.708; org.apache.solr.core.RequestHandlers; created defaults: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.708; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.708; org.apache.solr.core.RequestHandlers; created lazy: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.708; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.709; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.711; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.714; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@9db74a9 main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.715; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.715; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.716; org.apache.solr.handler.SnapPuller; Poll Scheduled at an interval of 1000ms
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.716; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.716; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@9db74a9 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.717; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.717; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.717; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.735; org.apache.solr.core.CoreContainer; Shutting down CoreContainer instance=654212203
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.737; org.apache.solr.core.SolrCore; [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@67f7bbdf
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.739; org.apache.solr.update.DirectUpdateHandler2; 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]   1> INFO  - 2013-04-28 08:32:34.739; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.741; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.741; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.743; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.743; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.745; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\index [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\index;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.745; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.746; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\ [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.747; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.749; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.805; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.811; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:57544
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.814; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.815; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.816; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.817; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.817; org.apache.solr.core.CoreContainer; New CoreContainer 1451287680
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.818; org.apache.solr.core.CoreContainer$Initializer; no solr.xml found. using default old-style solr.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.819; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.820; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.938; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.939; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.939; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.939; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.940; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.940; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.940; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.941; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.941; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.942; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.945; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.952; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:34.952; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\'
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.004; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.068; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.069; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.073; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.094; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.096; org.apache.solr.core.SolrCore; solr.NRTCachingDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.096; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\, dataDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.097; org.apache.solr.core.SolrCore; JMX monitoring not detected for core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.097; org.apache.solr.core.SolrCore; solr.NRTCachingDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.097; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.098; org.apache.solr.core.SolrCore; New index directory detected: old=null new=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\index/
[junit4:junit4]   1> WARN  - 2013-04-28 08:32:35.099; org.apache.solr.core.SolrCore; [collection1] Solr index directory '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.099; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.113; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954441\slave\collection1\data\index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@213fdeca; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.114; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.115; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.115; org.apache.solr.core.RequestHandlers; created defaults: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.115; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.115; org.apache.solr.core.RequestHandlers; created lazy: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.116; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.116; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.126; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.137; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1189857e main
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.137; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.137; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.137; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for  10000
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.138; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.138; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@1189857e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.139; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.139; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.139; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.167; org.apache.solr.core.CoreContainer; Shutting down CoreContainer instance=1585183078
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.168; org.apache.solr.core.SolrCore; [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7e7bb9f
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.168; org.apache.solr.update.DirectUpdateHandler2; 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]   1> INFO  - 2013-04-28 08:32:35.169; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.169; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.169; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.170; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.170; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.170; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\data\ [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\data\;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.170; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.170; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\data\index [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\data\index;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.171; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367137954069\master\collection1\data\index
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.172; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.227; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-28 08:32:35.238; org.eclipse.jetty

[...truncated too long message...]

ore.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=3 
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.914; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.917; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.923; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.924; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=3 
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.932; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.933; org.apache.solr.core.SolrCore; [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=6 
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.934; org.apache.solr.SolrTestCaseJ4; ###Ending doTestSnapPullWithMasterUrl
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.948; org.apache.solr.core.CoreContainer; Shutting down CoreContainer instance=50738847
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.951; org.apache.solr.core.SolrCore; [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1c198fc5
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.952; org.apache.solr.update.DirectUpdateHandler2; closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=496,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.953; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.953; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.954; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.957; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.958; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.958; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038482\master\collection1\data\ [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038482\master\collection1\data\;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.960; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038482\master\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.960; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038482\master\collection1\data\index.20130428043401688 [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038482\master\collection1\data\index.20130428043401688;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.961; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038482\master\collection1\data\index.20130428043401688
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:01.962; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.030; org.apache.solr.core.CoreContainer; Shutting down CoreContainer instance=631263306
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.032; org.apache.solr.core.SolrCore; [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@513d09cd
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.032; org.apache.solr.update.DirectUpdateHandler2; closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=3,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.034; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.034; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.035; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.038; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.038; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.039; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038822\slave\collection1\data\index.20130428043401333 [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038822\slave\collection1\data\index.20130428043401333;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.040; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038822\slave\collection1\data\index.20130428043401333
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.040; org.apache.solr.core.CachingDirectoryFactory; looking to close .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038822\slave\collection1\data\ [CachedDir<<refCount=0;path=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038822\slave\collection1\data\;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.042; org.apache.solr.core.CachingDirectoryFactory; Closing directory: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1367138038822\slave\collection1\data\
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.043; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   1> INFO  - 2013-04-28 08:34:02.133; org.apache.solr.SolrTestCaseJ4; ###deleteCore
[junit4:junit4]   2> NOTE: test params are: codec=Appending, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=de_AT, timezone=America/Virgin
[junit4:junit4]   2> NOTE: Windows 7 6.1 amd64/Sun Microsystems Inc. 1.6.0_45 (64-bit)/cpus=2,threads=1,free=141162584,total=267517952
[junit4:junit4]   2> NOTE: All tests run in this JVM: [OpenCloseCoreStressTest, SOLR749Test, TestSolrXml, BinaryUpdateRequestHandlerTest, SuggesterTSTTest, QueryEqualityTest, TestQueryUtils, TestAddFieldRealTimeGet, TestWordDelimiterFilterFactory, PluginInfoTest, CollectionsAPIDistributedZkTest, PathHierarchyTokenizerFactoryTest, TestSort, SolrIndexConfigTest, SolrCoreTest, PreAnalyzedFieldTest, CoreContainerCoreInitFailuresTest, HighlighterTest, ShardRoutingTest, FieldAnalysisRequestHandlerTest, TestBinaryResponseWriter, DocumentAnalysisRequestHandlerTest, TestSweetSpotSimilarityFactory, TestStressLucene, TestRTGBase, TestLRUCache, JSONWriterTest, DebugComponentTest, TestMultiCoreConfBootstrap, SystemInfoHandlerTest, QueryParsingTest, SpatialFilterTest, DocValuesMultiTest, TestPhraseSuggestions, TestPHPSerializedResponseWriter, TestFastLRUCache, TestIndexSearcher, CSVRequestHandlerTest, SimpleFacetsTest, TestLMJelinekMercerSimilarityFactory, ShardRoutingCustomTest, HighlighterConfigTest, TestReplicationHandler]
[junit4:junit4] Completed in 92.17s, 13 tests, 1 failure <<< FAILURES!

[...truncated 780 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:384: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:364: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1243: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:887: There were test failures: 294 suites, 1222 tests, 1 failure, 18 ignored (12 assumptions)

Total time: 63 minutes 48 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message