You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/01/16 18:25:21 UTC
[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 496 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/496/
1 tests failed.
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload
Error Message:
expected:<[{indexVersion=1389890319307,generation=2,filelist=[_0.cfe, _0.cfs, _0.si, _1.cfe, _1.cfs, _1.si, _2.cfe, _2.cfs, _2.si, _3.cfe, _3.cfs, _3.si, _4.cfe, _4.cfs, _4.si, _5.cfe, _5.cfs, _5.si, segments_2]}]> but was:<[{indexVersion=1389890319307,generation=2,filelist=[_0.cfe, _0.cfs, _0.si, _1.cfe, _1.cfs, _1.si, _2.cfe, _2.cfs, _2.si, _3.cfe, _3.cfs, _3.si, _4.cfe, _4.cfs, _4.si, _5.cfe, _5.cfs, _5.si, segments_2]}, {indexVersion=1389890319307,generation=3,filelist=[_0.cfe, _0.cfs, _0.si, _1.cfe, _1.cfs, _1.si, _2.cfe, _2.cfs, _2.si, _3.cfe, _3.cfs, _3.si, _5.cfe, _5.cfs, _5.si, _6.cfe, _6.cfs, _6.si, segments_3]}]>
Stack Trace:
java.lang.AssertionError: expected:<[{indexVersion=1389890319307,generation=2,filelist=[_0.cfe, _0.cfs, _0.si, _1.cfe, _1.cfs, _1.si, _2.cfe, _2.cfs, _2.si, _3.cfe, _3.cfs, _3.si, _4.cfe, _4.cfs, _4.si, _5.cfe, _5.cfs, _5.si, segments_2]}]> but was:<[{indexVersion=1389890319307,generation=2,filelist=[_0.cfe, _0.cfs, _0.si, _1.cfe, _1.cfs, _1.si, _2.cfe, _2.cfs, _2.si, _3.cfe, _3.cfs, _3.si, _4.cfe, _4.cfs, _4.si, _5.cfe, _5.cfs, _5.si, segments_2]}, {indexVersion=1389890319307,generation=3,filelist=[_0.cfe, _0.cfs, _0.si, _1.cfe, _1.cfs, _1.si, _2.cfe, _2.cfs, _2.si, _3.cfe, _3.cfs, _3.si, _5.cfe, _5.cfs, _5.si, _6.cfe, _6.cfs, _6.si, segments_3]}]>
at __randomizedtesting.SeedInfo.seed([7C9AB8D9B6A387A0:594DA3E9C6EB89A3]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:147)
at org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload(TestReplicationHandler.java:1179)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10181 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> 444586 T604 oas.SolrTestCaseJ4.setUp ###Starting testEmptyCommits
[junit4] 2> 444607 T604 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 444611 T604 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:35195
[junit4] 2> 444612 T604 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 444612 T604 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 444613 T604 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master
[junit4] 2> 444613 T604 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/'
[junit4] 2> 444652 T604 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/solr.xml
[junit4] 2> 444752 T604 oasc.CoreContainer.<init> New CoreContainer 1894348699
[junit4] 2> 444753 T604 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/]
[junit4] 2> 444754 T604 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 444755 T604 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 444755 T604 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 444756 T604 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 444756 T604 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 444756 T604 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 444757 T604 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 444757 T604 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 444758 T604 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 444771 T604 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 444771 T604 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 444771 T604 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 444778 T614 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1
[junit4] 2> 444778 T614 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/'
[junit4] 2> 444820 T614 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 444866 T614 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 444867 T614 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 444872 T614 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 444890 T614 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 444891 T614 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 444891 T614 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/data/
[junit4] 2> 444892 T614 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 444892 T614 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/data
[junit4] 2> 444892 T614 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/data/index/
[junit4] 2> 444893 T614 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 444893 T614 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/data/index
[junit4] 2> 444894 T614 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=45, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 444895 T614 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_1,generation=1}
[junit4] 2> 444895 T614 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 444896 T614 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 444896 T614 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 444896 T614 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 444897 T614 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 444897 T614 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 444897 T614 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 444897 T614 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 444909 T614 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 444912 T614 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 444912 T614 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 444912 T614 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@5f3d9150
[junit4] 2> 444913 T614 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_1,generation=1}
[junit4] 2> 444913 T614 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 444913 T614 oass.SolrIndexSearcher.<init> Opening Searcher@21490544 main
[junit4] 2> 444914 T614 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 444914 T614 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 444914 T615 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@21490544 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 444914 T614 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 444915 T604 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 444916 T604 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 444929 T604 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 444931 T604 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:58914
[junit4] 2> 444932 T604 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 444933 T604 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 444933 T604 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave
[junit4] 2> 444933 T604 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/'
[junit4] 2> 444949 T604 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/solr.xml
[junit4] 2> 445014 T604 oasc.CoreContainer.<init> New CoreContainer 181342910
[junit4] 2> 445014 T604 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/]
[junit4] 2> 445016 T604 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 445017 T604 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 445017 T604 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 445017 T604 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 445018 T604 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 445018 T604 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 445019 T604 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 445019 T604 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 445019 T604 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 445032 T604 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 445032 T604 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 445033 T604 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 445039 T626 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1
[junit4] 2> 445039 T626 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/'
[junit4] 2> 445094 T626 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 445156 T626 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 445157 T626 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 445164 T626 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 445183 T626 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 445185 T626 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 445185 T626 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/
[junit4] 2> 445185 T626 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 445186 T626 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data
[junit4] 2> 445186 T626 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index/
[junit4] 2> 445186 T626 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 445188 T626 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index
[junit4] 2> 445188 T626 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=45, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 445189 T626 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_1,generation=1}
[junit4] 2> 445190 T626 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 445191 T626 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 445191 T626 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 445192 T626 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 445192 T626 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 445192 T626 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 445193 T626 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 445193 T626 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 445195 T626 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 445198 T626 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 445198 T626 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 445199 T626 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@7ac12f3e
[junit4] 2> 445199 T626 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_1,generation=1}
[junit4] 2> 445200 T626 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 445200 T626 oass.SolrIndexSearcher.<init> Opening Searcher@428b1ec7 main
[junit4] 2> 445207 T626 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 445208 T627 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@428b1ec7 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 445208 T626 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 445209 T604 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 445209 T604 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> ASYNC NEW_CORE C204 name=collection1 org.apache.solr.core.SolrCore@3c0f3c3e
[junit4] 2> 445219 T607 C204 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=*:*&wt=javabin&sort=id+desc} hits=0 status=0 QTime=7
[junit4] 2> 445224 T607 C204 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[1]} 0 1
[junit4] 2> 445228 T607 C204 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 445231 T607 C204 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_2,generation=2}
[junit4] 2> 445232 T607 C204 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 445233 T607 C204 oass.SolrIndexSearcher.<init> Opening Searcher@3df4fd50 main
[junit4] 2> 445234 T607 C204 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 445234 T615 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3df4fd50 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):c1)}
[junit4] 2> 445235 T607 C204 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin&commit=true} {commit=} 0 7
[junit4] 2> 445238 T630 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 445239 T630 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 445241 T608 C204 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445242 T630 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4] 2> 445242 T630 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4] 2> 445242 T630 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 445252 T608 C204 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=filelist&generation=2&qt=/replication} status=0 QTime=8
[junit4] 2> 445253 T630 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 4
[junit4] 2> 445254 T630 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104689
[junit4] 2> 445254 T630 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 445254 T630 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 445254 T630 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 445255 T630 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@3b4002e7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1b1bb183) fullCopy=false
[junit4] 2> 445258 T608 C204 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_0.cfe&command=filecontent&generation=2&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445262 T608 C204 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=segments_2&command=filecontent&generation=2&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445265 T608 C204 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_0.cfs&command=filecontent&generation=2&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C205 name=collection1 org.apache.solr.core.SolrCore@3c0f3c3e
[junit4] 2> 445274 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_0.si&command=filecontent&generation=2&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445276 T630 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 445277 T630 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 445278 T630 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=37.0703125, floorSegmentMB=1.5966796875, forceMergeDeletesPctAllowed=27.061077867454483, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 445279 T630 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_2,generation=2}
[junit4] 2> 445279 T630 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 445280 T630 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 445281 T630 oass.SolrIndexSearcher.<init> Opening Searcher@79e13dcd main
[junit4] 2> 445281 T627 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@79e13dcd main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):c1)}
[junit4] 2> 445282 T630 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104689 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104689;done=true>>]
[junit4] 2> 445282 T630 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104689
[junit4] 2> ASYNC NEW_CORE C206 name=collection1 org.apache.solr.core.SolrCore@378d0069
[junit4] 2> 445282 T619 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:35195/solr/replication} status=0 QTime=44
[junit4] 2> 445400 T620 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=name:empty1&wt=javabin&sort=id+desc} hits=1 status=0 QTime=115
[junit4] 2> 445404 T607 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=getDetails&wt=javabin&command=details&qt=/replication} status=0 QTime=1
[junit4] 2> 445408 T607 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=getDetails&wt=javabin&command=details&qt=/replication} status=0 QTime=0
[junit4] 2> 445414 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=details&slave=false&qt=/replication} status=0 QTime=0
[junit4] 2> 445415 T620 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=getDetails&wt=javabin&command=details&qt=/replication} status=0 QTime=4
[junit4] 2> 445418 T607 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=assertVersions&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445421 T620 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=assertVersions&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445424 T607 C205 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 445425 T607 C205 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 445425 T607 C205 oass.SolrIndexSearcher.<init> Opening Searcher@1768f5f4 main
[junit4] 2> 445425 T607 C205 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 445426 T615 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1768f5f4 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):c1)}
[junit4] 2> 445426 T607 C205 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin&commit=true} {commit=} 0 2
[junit4] 2> 445428 T632 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 445428 T632 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 445431 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445432 T632 oash.SnapPuller.fetchLatestIndex Slave in sync with master.
[junit4] 2> 445432 T619 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:35195/solr/replication} status=0 QTime=5
[junit4] 2> 445436 T607 C205 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[2]} 0 1
[junit4] 2> 445439 T607 C205 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 445442 T607 C205 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_3,generation=3}
[junit4] 2> 445442 T607 C205 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 445443 T607 C205 oass.SolrIndexSearcher.<init> Opening Searcher@64232a03 main
[junit4] 2> 445444 T607 C205 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 445444 T615 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@64232a03 main{StandardDirectoryReader(segments_3:5:nrt _0(5.0):c1 _1(5.0):c1)}
[junit4] 2> 445445 T607 C205 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin&commit=true} {commit=} 0 6
[junit4] 2> 445446 T633 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 445447 T633 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 445449 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445450 T633 oash.SnapPuller.fetchLatestIndex Master's generation: 3
[junit4] 2> 445450 T633 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
[junit4] 2> 445450 T633 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 445454 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=filelist&generation=3&qt=/replication} status=0 QTime=1
[junit4] 2> 445455 T633 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 7
[junit4] 2> 445455 T633 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104891
[junit4] 2> 445456 T633 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 445456 T633 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 445456 T633 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 445457 T633 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@75d7b18c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@133e6e57) fullCopy=false
[junit4] 2> 445460 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_1.cfs&command=filecontent&generation=3&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445462 T633 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfe because it already exists
[junit4] 2> 445464 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_1.si&command=filecontent&generation=3&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445468 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=segments_3&command=filecontent&generation=3&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445472 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_1.cfe&command=filecontent&generation=3&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445473 T633 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfs because it already exists
[junit4] 2> 445473 T633 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 445474 T633 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 445476 T633 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 445476 T633 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=37.0703125, floorSegmentMB=1.5966796875, forceMergeDeletesPctAllowed=27.061077867454483, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 445478 T633 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_3,generation=3}
[junit4] 2> 445478 T633 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 445478 T633 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 445480 T633 oass.SolrIndexSearcher.<init> Opening Searcher@59f3a791 main
[junit4] 2> 445481 T627 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@59f3a791 main{StandardDirectoryReader(segments_3:5:nrt _0(5.0):c1 _1(5.0):c1)}
[junit4] 2> 445481 T633 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104891 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104891;done=true>>]
[junit4] 2> 445481 T633 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104891
[junit4] 2> 445482 T619 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:35195/solr/replication} status=0 QTime=36
[junit4] 2> 445486 T620 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=name:empty2&wt=javabin&sort=id+desc} hits=1 status=0 QTime=1
[junit4] 2> 445489 T607 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=getDetails&wt=javabin&command=details&qt=/replication} status=0 QTime=0
[junit4] 2> 445492 T607 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=getDetails&wt=javabin&command=details&qt=/replication} status=0 QTime=0
[junit4] 2> 445498 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=details&slave=false&qt=/replication} status=0 QTime=0
[junit4] 2> 445499 T620 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=getDetails&wt=javabin&command=details&qt=/replication} status=0 QTime=4
[junit4] 2> 445503 T607 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=assertVersions&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445506 T620 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=assertVersions&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445510 T607 C205 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[3]} 0 1
[junit4] 2> 445513 T607 C205 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 445516 T607 C205 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_4,generation=4}
[junit4] 2> 445516 T607 C205 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 445518 T607 C205 oass.SolrIndexSearcher.<init> Opening Searcher@51bb1659 realtime
[junit4] 2> 445518 T607 C205 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 445518 T607 C205 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin&commit=true&openSearcher=false} {commit=} 0 5
[junit4] 2> 445520 T635 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 445521 T635 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 445523 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445524 T635 oash.SnapPuller.fetchLatestIndex Master's generation: 4
[junit4] 2> 445524 T635 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
[junit4] 2> 445525 T635 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 445528 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=filelist&generation=4&qt=/replication} status=0 QTime=1
[junit4] 2> 445529 T635 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
[junit4] 2> 445530 T635 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104965
[junit4] 2> 445530 T635 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 445531 T635 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 445531 T635 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 445532 T635 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@11fa560c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7f2c8ce2) fullCopy=false
[junit4] 2> 445532 T635 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfs because it already exists
[junit4] 2> 445532 T635 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfe because it already exists
[junit4] 2> 445532 T635 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4] 2> 445535 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_2.si&command=filecontent&generation=4&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445539 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_2.cfs&command=filecontent&generation=4&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445543 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=segments_4&command=filecontent&generation=4&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445544 T635 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfe because it already exists
[junit4] 2> 445545 T635 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfs because it already exists
[junit4] 2> 445545 T635 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 445548 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_2.cfe&command=filecontent&generation=4&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445549 T635 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 445552 T635 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 445553 T635 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=37.0703125, floorSegmentMB=1.5966796875, forceMergeDeletesPctAllowed=27.061077867454483, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 445555 T635 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=3
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_4,generation=4}
[junit4] 2> 445555 T635 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 445556 T635 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 445560 T635 oass.SolrIndexSearcher.<init> Opening Searcher@7c7660b1 main
[junit4] 2> 445560 T627 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7c7660b1 main{StandardDirectoryReader(segments_4:7:nrt _0(5.0):c1 _1(5.0):c1 _2(5.0):c1)}
[junit4] 2> 445561 T635 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104965 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104965;done=true>>]
[junit4] 2> 445561 T635 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213104965
[junit4] 2> 445562 T619 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:35195/solr/replication} status=0 QTime=42
[junit4] 2> 445566 T607 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=name:empty3&wt=javabin&sort=id+desc} hits=0 status=0 QTime=1
[junit4] 2> 445567 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445568 T628 oash.SnapPuller.fetchLatestIndex Slave in sync with master.
[junit4] 2> 445570 T620 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=name:empty3&wt=javabin&sort=id+desc} hits=1 status=0 QTime=1
[junit4] 2> 445574 T607 C205 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[4]} 0 1
[junit4] 2> 445577 T607 C205 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 445580 T607 C205 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=4
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@35fbadc6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e4dbdda),segFN=segments_5,generation=5}
[junit4] 2> 445580 T607 C205 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 445582 T607 C205 oass.SolrIndexSearcher.<init> Opening Searcher@42fc5ce9 main
[junit4] 2> 445583 T607 C205 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 445583 T615 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@42fc5ce9 main{StandardDirectoryReader(segments_5:9:nrt _0(5.0):c1 _1(5.0):c1 _2(5.0):c1 _3(5.0):c1)}
[junit4] 2> 445583 T607 C205 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin&commit=true} {commit=} 0 6
[junit4] 2> 445586 T637 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 445586 T637 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 445589 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445590 T637 oash.SnapPuller.fetchLatestIndex Master's generation: 5
[junit4] 2> 445590 T637 oash.SnapPuller.fetchLatestIndex Slave's generation: 4
[junit4] 2> 445591 T637 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 445594 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=filelist&generation=5&qt=/replication} status=0 QTime=0
[junit4] 2> 445594 T637 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 13
[junit4] 2> 445595 T637 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213105031
[junit4] 2> 445596 T637 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 445596 T637 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 445596 T637 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 445598 T637 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6b38438c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4a2b5f8f) fullCopy=false
[junit4] 2> 445598 T637 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfs because it already exists
[junit4] 2> 445598 T637 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfe because it already exists
[junit4] 2> 445599 T637 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfe because it already exists
[junit4] 2> 445599 T637 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 445601 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_3.cfs&command=filecontent&generation=5&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445603 T637 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4] 2> 445603 T637 oash.SnapPuller.downloadIndexFiles Skipping download for _2.si because it already exists
[junit4] 2> 445603 T637 oash.SnapPuller.downloadIndexFiles Skipping download for _2.cfs because it already exists
[junit4] 2> 445603 T637 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfs because it already exists
[junit4] 2> 445606 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=segments_5&command=filecontent&generation=5&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445607 T637 oash.SnapPuller.downloadIndexFiles Skipping download for _2.cfe because it already exists
[junit4] 2> 445610 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_3.cfe&command=filecontent&generation=5&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445614 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=filestream&file=_3.si&command=filecontent&generation=5&checksum=true&qt=/replication} status=0 QTime=0
[junit4] 2> 445615 T637 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 445617 T637 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 445618 T637 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=37.0703125, floorSegmentMB=1.5966796875, forceMergeDeletesPctAllowed=27.061077867454483, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 445620 T637 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=4
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@79789b9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d2fd9c3),segFN=segments_5,generation=5}
[junit4] 2> 445620 T637 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 445621 T637 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 445624 T637 oass.SolrIndexSearcher.<init> Opening Searcher@1b766004 main
[junit4] 2> 445625 T627 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b766004 main{StandardDirectoryReader(segments_5:9:nrt _0(5.0):c1 _1(5.0):c1 _2(5.0):c1 _3(5.0):c1)}
[junit4] 2> 445625 T637 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213105031 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213105031;done=true>>]
[junit4] 2> 445625 T637 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index.20140116213105031
[junit4] 2> 445626 T621 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:35195/solr/replication} status=0 QTime=41
[junit4] 2> 445632 T607 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=name:(empty1+empty2+empty3+empty4)&wt=javabin&sort=id+desc} hits=4 status=0 QTime=2
[junit4] 2> 445638 T620 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=name:(empty1+empty2+empty3+empty4)&wt=javabin&sort=id+desc} hits=4 status=0 QTime=2
[junit4] 2> 445642 T607 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=getDetails&wt=javabin&command=details&qt=/replication} status=0 QTime=0
[junit4] 2> 445645 T607 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=getDetails&wt=javabin&command=details&qt=/replication} status=0 QTime=0
[junit4] 2> 445651 T608 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&wt=javabin&command=details&slave=false&qt=/replication} status=0 QTime=0
[junit4] 2> 445653 T620 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=getDetails&wt=javabin&command=details&qt=/replication} status=0 QTime=5
[junit4] 2> 445656 T607 C205 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=assertVersions&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445659 T620 C206 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={version=2&_trace=assertVersions&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4] 2> 445660 T604 oas.SolrTestCaseJ4.tearDown ###Ending testEmptyCommits
[junit4] 2> 445661 T604 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1894348699
[junit4] 2> 445661 T604 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3c0f3c3e
[junit4] 2> 445662 T604 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=5,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=4,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 445663 T604 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 445663 T604 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 445664 T604 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 445665 T604 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 445667 T604 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 445667 T604 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/data/index;done=false>>]
[junit4] 2> 445667 T604 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/data/index
[junit4] 2> 445675 T604 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/data;done=false>>]
[junit4] 2> 445676 T604 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864023/master/collection1/data
[junit4] 2> 445676 T604 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 445729 T604 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=181342910
[junit4] 2> 445730 T604 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@378d0069
[junit4] 2> 445730 T604 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 445731 T604 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 445731 T604 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 445732 T604 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 445733 T604 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 445734 T604 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 445735 T604 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index;done=false>>]
[junit4] 2> 445735 T604 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data/index
[junit4] 2> 445742 T604 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data;done=false>>]
[junit4] 2> 445743 T604 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889864352/slave/collection1/data
[junit4] 2> 445744 T604 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 445814 T604 oas.SolrTestCaseJ4.setUp ###Starting doTestReplicateAfterStartupWithNoActivity
[junit4] 2> 445836 T604 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 445839 T604 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:23261
[junit4] 2> 445839 T604 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 445840 T604 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 445840 T604 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master
[junit4] 2> 445841 T604 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/'
[junit4] 2> 445880 T604 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/solr.xml
[junit4] 2> 445977 T604 oasc.CoreContainer.<init> New CoreContainer 769250630
[junit4] 2> 445977 T604 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/]
[junit4] 2> 445979 T604 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 445979 T604 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 445980 T604 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 445980 T604 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 445981 T604 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 445981 T604 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 445981 T604 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 445982 T604 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 445982 T604 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 445994 T604 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 445995 T604 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 445995 T604 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 446002 T648 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/collection1
[junit4] 2> 446002 T648 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/collection1/'
[junit4] 2> 446067 T648 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 446140 T648 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 446141 T648 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 446149 T648 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 446176 T648 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 446178 T648 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 446179 T648 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/collection1/data/
[junit4] 2> 446179 T648 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 446180 T648 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/collection1/data
[junit4] 2> 446180 T648 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/collection1/data/index/
[junit4] 2> 446180 T648 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 446181 T648 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/collection1/data/index
[junit4] 2> 446181 T648 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=45, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 446183 T648 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@93fc45d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3974ba69),segFN=segments_1,generation=1}
[junit4] 2> 446183 T648 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 446184 T648 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 446185 T648 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 446185 T648 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 446185 T648 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 446186 T648 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 446186 T648 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 446187 T648 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 446207 T648 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 446210 T648 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 446211 T648 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 446211 T648 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@2d4c4ee
[junit4] 2> 446212 T648 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@93fc45d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3974ba69),segFN=segments_1,generation=1}
[junit4] 2> 446212 T648 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 446213 T648 oass.SolrIndexSearcher.<init> Opening Searcher@5e3ea5b2 main
[junit4] 2> 446213 T648 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 446213 T648 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 446214 T649 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5e3ea5b2 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 446214 T648 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 446215 T604 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 446215 T604 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 446229 T604 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 446232 T604 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:51783
[junit4] 2> 446232 T604 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 446233 T604 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 446233 T604 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave
[junit4] 2> 446234 T604 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/'
[junit4] 2> 446250 T604 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/solr.xml
[junit4] 2> 446320 T604 oasc.CoreContainer.<init> New CoreContainer 807248711
[junit4] 2> 446321 T604 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/]
[junit4] 2> 446323 T604 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 446323 T604 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 446324 T604 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 446324 T604 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 446324 T604 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 446325 T604 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 446325 T604 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 446325 T604 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 446326 T604 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 446337 T604 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 446337 T604 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 446338 T604 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 446344 T660 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1
[junit4] 2> 446344 T660 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/'
[junit4] 2> 446399 T660 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 446461 T660 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 446462 T660 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 446469 T660 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 446488 T660 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 446489 T660 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 446490 T660 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/data/
[junit4] 2> 446490 T660 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 446491 T660 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/data
[junit4] 2> 446491 T660 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/data/index/
[junit4] 2> 446492 T660 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 446492 T660 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/data/index
[junit4] 2> 446493 T660 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=45, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 446494 T660 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@798b9306 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3a61ad41),segFN=segments_1,generation=1}
[junit4] 2> 446494 T660 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 446495 T660 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 446495 T660 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 446496 T660 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 446496 T660 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 446496 T660 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 446497 T660 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 446497 T660 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 446499 T660 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 446502 T660 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 446502 T660 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 446503 T660 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@56b9a873
[junit4] 2> 446503 T660 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@798b9306 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3a61ad41),segFN=segments_1,generation=1}
[junit4] 2> 446504 T660 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 446504 T660 oass.SolrIndexSearcher.<init> Opening Searcher@407bfda6 main
[junit4] 2> 446505 T660 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 446505 T661 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@407bfda6 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 446505 T660 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 446506 T604 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 446507 T604 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 446507 T604 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=807248711
[junit4] 2> 446508 T604 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@39dfc9c6
[junit4] 2> 446509 T604 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 446509 T604 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 446510 T604 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 446510 T604 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 446511 T604 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 446512 T604 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 446512 T604 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/data/index;done=false>>]
[junit4] 2> 446513 T604 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/data/index
[junit4] 2> 446513 T604 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/data;done=false>>]
[junit4] 2> 446514 T604 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865652/slave/collection1/data
[junit4] 2> 446515 T604 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> ASYNC NEW_CORE C207 name=collection1 org.apache.solr.core.SolrCore@7a30635f
[junit4] 2> 446569 T641 C207 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 446570 T641 C207 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:*} 0 1
[junit4] 2> 446573 T641 C207 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 446574 T641 C207 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@93fc45d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3974ba69),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@93fc45d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3974ba69),segFN=segments_2,generation=2}
[junit4] 2> 446575 T641 C207 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 446575 T641 C207 oass.SolrIndexSearcher.<init> Opening Searcher@3befbc61 main
[junit4] 2> 446576 T641 C207 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 446576 T649 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3befbc61 main{StandardDirectoryReader(segments_2:2:nrt)}
[junit4] 2> 446577 T641 C207 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin&commit=true&waitSearcher=true&softCommit=false} {commit=} 0 4
[junit4] 2> 446581 T604 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=769250630
[junit4] 2> 446582 T604 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@7a30635f
[junit4] 2> 446582 T604 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4] 2> 446583 T604 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 446583 T604 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 446584 T604 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 446585 T604 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 446585 T604 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 446586 T604 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/master/collection1/data/index;done=false>>]
[junit4] 2> 446586 T604 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389889865250/
[...truncated too long message...]
4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2> Caused by: java.lang.RuntimeException: Interrupted while waiting for core reload to finish
[junit4] 2> at org.apache.solr.handler.SnapPuller.reloadCore(SnapPuller.java:721)
[junit4] 2> at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:473)
[junit4] 2> ... 10 more
[junit4] 2> Caused by: java.lang.InterruptedException
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:996)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1303)
[junit4] 2> at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:236)
[junit4] 2> at org.apache.solr.handler.SnapPuller.reloadCore(SnapPuller.java:718)
[junit4] 2> ... 11 more
[junit4] 2>
[junit4] 2> 1145886 T1543 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 1145887 T1543 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> ASYNC NEW_CORE C961 name=collection1 org.apache.solr.core.SolrCore@30c9666d
[junit4] 2> 1145948 T1531 C961 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=*:*&wt=javabin&sort=id+desc} hits=1 status=0 QTime=1
[junit4] 2> 1145949 T604 oas.SolrTestCaseJ4.tearDown ###Ending doTestIndexAndConfigReplication
[junit4] 2> 1145950 T604 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1554728497
[junit4] 2> 1145951 T604 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5986dad2
[junit4] 2> 1145951 T604 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 1145952 T604 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1145952 T604 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1145953 T604 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1145954 T604 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 1145954 T604 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1145955 T604 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561225/master/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561225/master/collection1/data;done=false>>]
[junit4] 2> 1145955 T604 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561225/master/collection1/data
[junit4] 2> 1145955 T604 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561225/master/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561225/master/collection1/data/index;done=false>>]
[junit4] 2> 1145956 T604 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561225/master/collection1/data/index
[junit4] 2> 1145958 T604 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 1146010 T604 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=525692612
[junit4] 2> 1146011 T604 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@30c9666d
[junit4] 2> 1146012 T604 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 1146012 T604 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1146012 T604 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1146013 T604 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1146014 T604 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 1146014 T604 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1146014 T604 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561634/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561634/slave/collection1/data;done=false>>]
[junit4] 2> 1146015 T604 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561634/slave/collection1/data
[junit4] 2> 1146015 T604 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561634/slave/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561634/slave/collection1/data/index;done=false>>]
[junit4] 2> 1146016 T604 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389890561634/slave/collection1/data/index
[junit4] 2> 1146018 T604 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 1146086 T604 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=uk_UA, timezone=Asia/Ashgabat
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=67627520,total=219480064
[junit4] 2> NOTE: All tests run in this JVM: [TestSuggestSpellingConverter, TestElisionMultitermQuery, TestExtendedDismaxParser, ModifyConfFileTest, ShardSplitTest, HdfsDirectoryTest, CSVRequestHandlerTest, SolrIndexSplitterTest, TestReloadAndDeleteDocs, DeleteReplicaTest, MBeansHandlerTest, TestSurroundQueryParser, SolrCoreTest, SpatialFilterTest, MoreLikeThisHandlerTest, BadComponentTest, IndexSchemaTest, CoreAdminCreateDiscoverTest, TestCoreContainer, HdfsBasicDistributedZkTest, TestPseudoReturnFields, TestDynamicFieldCollectionResource, TestLFUCache, TestQueryUtils, TestReplicationHandler]
[junit4] Completed on J0 in 701.54s, 14 tests, 1 failure <<< FAILURES!
[...truncated 804 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:460: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:433: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1304: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:937: There were test failures: 364 suites, 1596 tests, 1 failure, 32 ignored (4 assumptions)
Total time: 129 minutes 54 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 497 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/497/
1 tests failed.
FAILED: org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload
Error Message:
expected:<[{indexVersion=1389993887519,generation=2,filelist=[_kd.doc, _kd.fdt, _kd.fdx, _kd.fnm, _kd.nvd, _kd.nvm, _kd.si, _kd.tim, _kd.tip, _kh.cfe, _kh.cfs, _kh.si, _ki.cfe, _ki.cfs, _ki.si, _kj.cfe, _kj.cfs, _kj.si, _kp.cfe, _kp.cfs, _kp.si, _kq.cfe, _kq.cfs, _kq.si, segments_2]}]> but was:<[{indexVersion=1389993887519,generation=2,filelist=[_kd.doc, _kd.fdt, _kd.fdx, _kd.fnm, _kd.nvd, _kd.nvm, _kd.si, _kd.tim, _kd.tip, _kh.cfe, _kh.cfs, _kh.si, _ki.cfe, _ki.cfs, _ki.si, _kj.cfe, _kj.cfs, _kj.si, _kp.cfe, _kp.cfs, _kp.si, _kq.cfe, _kq.cfs, _kq.si, segments_2]}, {indexVersion=1389993887519,generation=3,filelist=[_kl.doc, _kl.fdt, _kl.fdx, _kl.fnm, _kl.nvd, _kl.nvm, _kl.si, _kl.tim, _kl.tip, _kp.cfe, _kp.cfs, _kp.si, _kq.cfe, _kq.cfs, _kq.si, segments_3]}]>
Stack Trace:
java.lang.AssertionError: expected:<[{indexVersion=1389993887519,generation=2,filelist=[_kd.doc, _kd.fdt, _kd.fdx, _kd.fnm, _kd.nvd, _kd.nvm, _kd.si, _kd.tim, _kd.tip, _kh.cfe, _kh.cfs, _kh.si, _ki.cfe, _ki.cfs, _ki.si, _kj.cfe, _kj.cfs, _kj.si, _kp.cfe, _kp.cfs, _kp.si, _kq.cfe, _kq.cfs, _kq.si, segments_2]}]> but was:<[{indexVersion=1389993887519,generation=2,filelist=[_kd.doc, _kd.fdt, _kd.fdx, _kd.fnm, _kd.nvd, _kd.nvm, _kd.si, _kd.tim, _kd.tip, _kh.cfe, _kh.cfs, _kh.si, _ki.cfe, _ki.cfs, _ki.si, _kj.cfe, _kj.cfs, _kj.si, _kp.cfe, _kp.cfs, _kp.si, _kq.cfe, _kq.cfs, _kq.si, segments_2]}, {indexVersion=1389993887519,generation=3,filelist=[_kl.doc, _kl.fdt, _kl.fdx, _kl.fnm, _kl.nvd, _kl.nvm, _kl.si, _kl.tim, _kl.tip, _kp.cfe, _kp.cfs, _kp.si, _kq.cfe, _kq.cfs, _kq.si, segments_3]}]>
at __randomizedtesting.SeedInfo.seed([6CEB54E60938E4F0:493C4FD67970EAF3]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:147)
at org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload(TestReplicationHandler.java:1179)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10016 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> 260291 T619 oas.SolrTestCaseJ4.setUp ###Starting doTestSnapPullWithMasterUrl
[junit4] 2> 260318 T619 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 260321 T619 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:20697
[junit4] 2> 260321 T619 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 260322 T619 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 260322 T619 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master
[junit4] 2> 260322 T619 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master/'
[junit4] 2> 260333 T619 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master/solr.xml
[junit4] 2> 260381 T619 oasc.CoreContainer.<init> New CoreContainer 449559015
[junit4] 2> 260382 T619 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master/]
[junit4] 2> 260383 T619 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 260383 T619 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 260383 T619 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 260383 T619 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 260384 T619 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 260384 T619 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 260384 T619 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 260384 T619 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 260385 T619 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 260393 T619 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 260394 T619 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 260394 T619 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 260398 T630 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master/collection1
[junit4] 2> 260399 T630 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master/collection1/'
[junit4] 2> 260443 T630 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 260489 T630 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 260490 T630 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 260495 T630 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 260512 T630 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 260513 T630 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 260514 T630 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master/collection1/data/
[junit4] 2> 260514 T630 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 260514 T630 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master/collection1/data
[junit4] 2> 260514 T630 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master/collection1/data/index/
[junit4] 2> 260514 T630 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 260515 T630 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388458/master/collection1/data/index
[junit4] 2> 260515 T630 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=8, maxMergeAtOnceExplicit=3, maxMergedSegmentMB=7.5830078125, floorSegmentMB=1.0771484375, forceMergeDeletesPctAllowed=23.18696870593876, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4734049918144364
[junit4] 2> 260516 T630 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4d947fd5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4a52a7f),segFN=segments_1,generation=1}
[junit4] 2> 260516 T630 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 260517 T630 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 260517 T630 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 260517 T630 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 260517 T630 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 260518 T630 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 260518 T630 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 260518 T630 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 260531 T630 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 260533 T630 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 260534 T630 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 260534 T630 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=4, maxMergeAtOnceExplicit=2, maxMergedSegmentMB=56.1376953125, floorSegmentMB=1.626953125, forceMergeDeletesPctAllowed=10.498266358242935, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8312803917514421
[junit4] 2> 260534 T630 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4d947fd5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4a52a7f),segFN=segments_1,generation=1}
[junit4] 2> 260534 T630 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 260535 T630 oass.SolrIndexSearcher.<init> Opening Searcher@13cf38f7 main
[junit4] 2> 260535 T630 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 260535 T630 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 260535 T631 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@13cf38f7 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 260535 T630 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 260536 T619 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 260536 T619 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 260547 T619 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 260549 T619 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:20698
[junit4] 2> 260549 T619 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 260550 T619 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 260550 T619 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave
[junit4] 2> 260550 T619 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/'
[junit4] 2> 260578 T619 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/solr.xml
[junit4] 2> 260646 T619 oasc.CoreContainer.<init> New CoreContainer 180362895
[junit4] 2> 260647 T619 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/]
[junit4] 2> 260648 T619 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 260648 T619 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 260648 T619 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 260648 T619 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 260649 T619 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 260649 T619 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 260649 T619 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 260649 T619 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 260650 T619 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 260658 T619 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 260658 T619 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 260659 T619 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 260663 T642 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1
[junit4] 2> 260664 T642 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/'
[junit4] 2> 260709 T642 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 260758 T642 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 260759 T642 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 260764 T642 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 260777 T642 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 260779 T642 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 260779 T642 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data/
[junit4] 2> 260779 T642 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 260779 T642 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data
[junit4] 2> 260780 T642 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data/index/
[junit4] 2> 260780 T642 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 260780 T642 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data/index
[junit4] 2> 260781 T642 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=8, maxMergeAtOnceExplicit=3, maxMergedSegmentMB=7.5830078125, floorSegmentMB=1.0771484375, forceMergeDeletesPctAllowed=23.18696870593876, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4734049918144364
[junit4] 2> 260781 T642 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@d10f642 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4be28e88),segFN=segments_1,generation=1}
[junit4] 2> 260782 T642 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 260782 T642 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 260783 T642 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 260783 T642 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 260783 T642 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 260783 T642 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 260783 T642 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 260784 T642 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 260785 T642 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 260788 T642 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 260788 T642 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 260788 T642 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=4, maxMergeAtOnceExplicit=2, maxMergedSegmentMB=56.1376953125, floorSegmentMB=1.626953125, forceMergeDeletesPctAllowed=10.498266358242935, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8312803917514421
[junit4] 2> 260789 T642 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@d10f642 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4be28e88),segFN=segments_1,generation=1}
[junit4] 2> 260789 T642 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 260789 T642 oass.SolrIndexSearcher.<init> Opening Searcher@5eb18ba3 main
[junit4] 2> 260795 T642 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 260796 T643 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5eb18ba3 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 260796 T642 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 260796 T619 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 260797 T619 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 260800 T619 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=180362895
[junit4] 2> 260801 T619 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@9b6df20
[junit4] 2> 260802 T619 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 260802 T619 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 260802 T619 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 260803 T619 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 260803 T619 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 260804 T619 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 260804 T619 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data;done=false>>]
[junit4] 2> 260804 T619 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data
[junit4] 2> 260805 T619 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data/index;done=false>>]
[junit4] 2> 260805 T619 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data/index
[junit4] 2> 260806 T619 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 260858 T619 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 260861 T619 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:20700
[junit4] 2> 260861 T619 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 260862 T619 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 260862 T619 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave
[junit4] 2> 260862 T619 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/'
[junit4] 2> 260873 T619 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/solr.xml
[junit4] 2> 260922 T619 oasc.CoreContainer.<init> New CoreContainer 1211751088
[junit4] 2> 260922 T619 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/]
[junit4] 2> 260923 T619 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 260924 T619 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 260924 T619 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 260924 T619 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 260924 T619 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 260925 T619 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 260925 T619 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 260925 T619 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 260925 T619 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 260935 T619 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 260935 T619 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 260935 T619 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 260940 T655 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1
[junit4] 2> 260940 T655 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/'
[junit4] 2> 260990 T655 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 261043 T655 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 261044 T655 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 261050 T655 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 261066 T655 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 261068 T655 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 261068 T655 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data/
[junit4] 2> 261068 T655 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 261069 T655 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data
[junit4] 2> 261069 T655 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data/index/
[junit4] 2> 261069 T655 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 261070 T655 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389993388703/slave/collection1/data/index
[junit4] 2> 261070 T655 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=8, maxMergeAtOnceExplicit=3, maxMergedSegmentMB=7.5830078125, floorSegmentMB=1.0771484375, forceMergeDeletesPctAllowed=23.18696870593876, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4734049918144364
[junit4] 2> 261071 T655 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@67ed0ae9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5658b4ec),segFN=segments_1,generation=1}
[junit4] 2> 261071 T655 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 261072 T655 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 261072 T655 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 261072 T655 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 261073 T655 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 261073 T655 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 261073 T655 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 261073 T655 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 261075 T655 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 261078 T655 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 261078 T655 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 261078 T655 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=4, maxMergeAtOnceExplicit=2, maxMergedSegmentMB=56.1376953125, floorSegmentMB=1.626953125, forceMergeDeletesPctAllowed=10.498266358242935, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8312803917514421
[junit4] 2> 261079 T655 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@67ed0ae9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5658b4ec),segFN=segments_1,generation=1}
[junit4] 2> 261079 T655 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 261079 T655 oass.SolrIndexSearcher.<init> Opening Searcher@5ace1a34 main
[junit4] 2> 261079 T655 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 261080 T656 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5ace1a34 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 261080 T655 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 261080 T619 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 261081 T619 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> ASYNC NEW_CORE C500 name=collection1 org.apache.solr.core.SolrCore@6d00e09f
[junit4] 2> 261083 T623 C500 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 261084 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:*} 0 1
[junit4] 2> ASYNC NEW_CORE C501 name=collection1 org.apache.solr.core.SolrCore@7d92c904
[junit4] 2> 261086 T648 C501 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 261086 T648 C501 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:*} 0 1
[junit4] 2> 261089 T648 C501 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 261090 T648 C501 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@67ed0ae9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5658b4ec),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@67ed0ae9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5658b4ec),segFN=segments_2,generation=2}
[junit4] 2> 261090 T648 C501 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 261091 T648 C501 oass.SolrIndexSearcher.<init> Opening Searcher@7cb0d614 main
[junit4] 2> 261091 T648 C501 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 261091 T656 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7cb0d614 main{StandardDirectoryReader(segments_2:2:nrt)}
[junit4] 2> 261091 T648 C501 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&wt=javabin&waitSearcher=true} {commit=} 0 2
[junit4] 2> 261095 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[0]} 0 1
[junit4] 2> 261097 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[1]} 0 0
[junit4] 2> 261100 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[2]} 0 0
[junit4] 2> 261103 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[3]} 0 0
[junit4] 2> 261107 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[4]} 0 1
[junit4] 2> 261109 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[5]} 0 0
[junit4] 2> 261112 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[6]} 0 0
[junit4] 2> 261115 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[7]} 0 0
[junit4] 2> 261118 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[8]} 0 0
[junit4] 2> 261121 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[9]} 0 0
[junit4] 2> 261124 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[10]} 0 0
[junit4] 2> 261127 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[11]} 0 0
[junit4] 2> 261130 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[12]} 0 0
[junit4] 2> 261133 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[13]} 0 0
[junit4] 2> 261136 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[14]} 0 0
[junit4] 2> 261139 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[15]} 0 0
[junit4] 2> 261142 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[16]} 0 0
[junit4] 2> 261145 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[17]} 0 0
[junit4] 2> 261148 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[18]} 0 0
[junit4] 2> 261151 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[19]} 0 0
[junit4] 2> 261154 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[20]} 0 0
[junit4] 2> 261157 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[21]} 0 0
[junit4] 2> 261160 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[22]} 0 0
[junit4] 2> 261163 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[23]} 0 0
[junit4] 2> 261166 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[24]} 0 0
[junit4] 2> 261169 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[25]} 0 0
[junit4] 2> 261172 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[26]} 0 0
[junit4] 2> 261176 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[27]} 0 1
[junit4] 2> 261178 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[28]} 0 0
[junit4] 2> 261181 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[29]} 0 0
[junit4] 2> 261184 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[30]} 0 0
[junit4] 2> 261187 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[31]} 0 0
[junit4] 2> 261190 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[32]} 0 0
[junit4] 2> 261193 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[33]} 0 0
[junit4] 2> 261197 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[34]} 0 1
[junit4] 2> 261200 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[35]} 0 0
[junit4] 2> 261203 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[36]} 0 0
[junit4] 2> 261206 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[37]} 0 0
[junit4] 2> 261209 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[38]} 0 0
[junit4] 2> 261212 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[39]} 0 0
[junit4] 2> 261215 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[40]} 0 0
[junit4] 2> 261218 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[41]} 0 0
[junit4] 2> 261221 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[42]} 0 0
[junit4] 2> 261224 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[43]} 0 0
[junit4] 2> 261227 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[44]} 0 0
[junit4] 2> 261230 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[45]} 0 0
[junit4] 2> 261233 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[46]} 0 0
[junit4] 2> 261236 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[47]} 0 0
[junit4] 2> 261240 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[48]} 0 1
[junit4] 2> 261242 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[49]} 0 0
[junit4] 2> 261245 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[50]} 0 0
[junit4] 2> 261248 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[51]} 0 0
[junit4] 2> 261251 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[52]} 0 0
[junit4] 2> 261254 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[53]} 0 0
[junit4] 2> 261258 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[54]} 0 1
[junit4] 2> 261260 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[55]} 0 0
[junit4] 2> 261263 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[56]} 0 0
[junit4] 2> 261266 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[57]} 0 0
[junit4] 2> 261270 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[58]} 0 0
[junit4] 2> 261272 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[59]} 0 0
[junit4] 2> 261275 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[60]} 0 0
[junit4] 2> 261278 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[61]} 0 0
[junit4] 2> 261282 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[62]} 0 0
[junit4] 2> 261284 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[63]} 0 0
[junit4] 2> 261287 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[64]} 0 0
[junit4] 2> 261290 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[65]} 0 0
[junit4] 2> 261293 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[66]} 0 0
[junit4] 2> 261296 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[67]} 0 0
[junit4] 2> 261299 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[68]} 0 0
[junit4] 2> 261302 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[69]} 0 0
[junit4] 2> 261305 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[70]} 0 0
[junit4] 2> 261308 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[71]} 0 0
[junit4] 2> 261311 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[72]} 0 0
[junit4] 2> 261315 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[73]} 0 0
[junit4] 2> 261318 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[74]} 0 0
[junit4] 2> 261320 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[75]} 0 0
[junit4] 2> 261323 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[76]} 0 0
[junit4] 2> 261326 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[77]} 0 0
[junit4] 2> 261329 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[78]} 0 0
[junit4] 2> 261332 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[79]} 0 0
[junit4] 2> 261335 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[80]} 0 0
[junit4] 2> 261338 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[81]} 0 0
[junit4] 2> 261341 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[82]} 0 0
[junit4] 2> 261345 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[83]} 0 1
[junit4] 2> 261347 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[84]} 0 0
[junit4] 2> 261350 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[85]} 0 0
[junit4] 2> 261353 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[86]} 0 0
[junit4] 2> 261356 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[87]} 0 0
[junit4] 2> 261359 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[88]} 0 0
[junit4] 2> 261362 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[89]} 0 0
[junit4] 2> 261365 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[90]} 0 0
[junit4] 2> 261369 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[91]} 0 1
[junit4] 2> 261371 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[92]} 0 0
[junit4] 2> 261374 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[93]} 0 0
[junit4] 2> 261377 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[94]} 0 0
[junit4] 2> 261380 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[95]} 0 0
[junit4] 2> 261383 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[96]} 0 0
[junit4] 2> 261386 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[97]} 0 0
[junit4] 2> 261389 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[98]} 0 0
[junit4] 2> 261392 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[99]} 0 0
[junit4] 2> 261395 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[100]} 0 0
[junit4] 2> 261399 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[101]} 0 1
[junit4] 2> 261402 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[102]} 0 0
[junit4] 2> 261405 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[103]} 0 0
[junit4] 2> 261408 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[104]} 0 0
[junit4] 2> 261411 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[105]} 0 0
[junit4] 2> 261414 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[106]} 0 0
[junit4] 2> 261417 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[107]} 0 0
[junit4] 2> 261420 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[108]} 0 0
[junit4] 2> 261423 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[109]} 0 0
[junit4] 2> 261426 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[110]} 0 0
[junit4] 2> 261429 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[111]} 0 0
[junit4] 2> 261433 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[112]} 0 1
[junit4] 2> 261436 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[113]} 0 0
[junit4] 2> 261440 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[114]} 0 1
[junit4] 2> 261442 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[115]} 0 0
[junit4] 2> 261445 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[116]} 0 0
[junit4] 2> 261448 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[117]} 0 0
[junit4] 2> 261451 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[118]} 0 0
[junit4] 2> 261454 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[119]} 0 0
[junit4] 2> 261457 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[120]} 0 0
[junit4] 2> 261460 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[121]} 0 0
[junit4] 2> 261463 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[122]} 0 0
[junit4] 2> 261466 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[123]} 0 0
[junit4] 2> 261469 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[124]} 0 0
[junit4] 2> 261472 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[125]} 0 0
[junit4] 2> 261475 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[126]} 0 0
[junit4] 2> 261479 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[127]} 0 1
[junit4] 2> 261482 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[128]} 0 0
[junit4] 2> 261485 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[129]} 0 0
[junit4] 2> 261488 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[130]} 0 0
[junit4] 2> 261491 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[131]} 0 0
[junit4] 2> 261494 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[132]} 0 0
[junit4] 2> 261497 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[133]} 0 0
[junit4] 2> 261500 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[134]} 0 0
[junit4] 2> 261503 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[135]} 0 0
[junit4] 2> 261506 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[136]} 0 0
[junit4] 2> 261509 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[137]} 0 0
[junit4] 2> 261512 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[138]} 0 0
[junit4] 2> 261515 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[139]} 0 0
[junit4] 2> 261518 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[140]} 0 0
[junit4] 2> 261521 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[141]} 0 0
[junit4] 2> 261524 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[142]} 0 0
[junit4] 2> 261527 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[143]} 0 0
[junit4] 2> 261530 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[144]} 0 0
[junit4] 2> 261533 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[145]} 0 0
[junit4] 2> 261536 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[146]} 0 0
[junit4] 2> 261539 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[147]} 0 0
[junit4] 2> 261542 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[148]} 0 0
[junit4] 2> 261545 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[149]} 0 0
[junit4] 2> 261548 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[150]} 0 0
[junit4] 2> 261551 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[151]} 0 0
[junit4] 2> 261554 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[152]} 0 0
[junit4] 2> 261557 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[153]} 0 0
[junit4] 2> 261560 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[154]} 0 0
[junit4] 2> 261563 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[155]} 0 0
[junit4] 2> 261566 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[156]} 0 0
[junit4] 2> 261569 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[157]} 0 0
[junit4] 2> 261572 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[158]} 0 0
[junit4] 2> 261575 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[159]} 0 0
[junit4] 2> 261578 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[160]} 0 0
[junit4] 2> 261581 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[161]} 0 0
[junit4] 2> 261584 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[162]} 0 0
[junit4] 2> 261587 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[163]} 0 0
[junit4] 2> 261590 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[164]} 0 0
[junit4] 2> 261593 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[165]} 0 0
[junit4] 2> 261596 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[166]} 0 0
[junit4] 2> 261599 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[167]} 0 0
[junit4] 2> 261602 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[168]} 0 0
[junit4] 2> 261605 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[169]} 0 0
[junit4] 2> 261608 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[170]} 0 0
[junit4] 2> 261611 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[171]} 0 0
[junit4] 2> 261615 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[172]} 0 1
[junit4] 2> 261618 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[173]} 0 0
[junit4] 2> 261621 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[174]} 0 0
[junit4] 2> 261624 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[175]} 0 0
[junit4] 2> 261627 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[176]} 0 0
[junit4] 2> 261630 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[177]} 0 0
[junit4] 2> 261634 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[178]} 0 1
[junit4] 2> 261636 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[179]} 0 0
[junit4] 2> 261639 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[180]} 0 0
[junit4] 2> 261642 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[181]} 0 0
[junit4] 2> 261645 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[182]} 0 0
[junit4] 2> 261648 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[183]} 0 0
[junit4] 2> 261651 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[184]} 0 0
[junit4] 2> 261654 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[185]} 0 0
[junit4] 2> 261658 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[186]} 0 1
[junit4] 2> 261660 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[187]} 0 0
[junit4] 2> 261663 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[188]} 0 0
[junit4] 2> 261666 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[189]} 0 0
[junit4] 2> 261669 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[190]} 0 0
[junit4] 2> 261672 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[191]} 0 0
[junit4] 2> 261676 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[192]} 0 1
[junit4] 2> 261678 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[193]} 0 0
[junit4] 2> 261681 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[194]} 0 0
[junit4] 2> 261684 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[195]} 0 0
[junit4] 2> 261687 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[196]} 0 0
[junit4] 2> 261690 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[197]} 0 0
[junit4] 2> 261693 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[198]} 0 0
[junit4] 2> 261696 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[199]} 0 0
[junit4] 2> 261699 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[200]} 0 0
[junit4] 2> 261703 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[201]} 0 1
[junit4] 2> 261705 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[202]} 0 0
[junit4] 2> 261708 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[203]} 0 0
[junit4] 2> 261711 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[204]} 0 0
[junit4] 2> 261714 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[205]} 0 0
[junit4] 2> 261717 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[206]} 0 0
[junit4] 2> 261720 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[207]} 0 0
[junit4] 2> 261723 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[208]} 0 0
[junit4] 2> 261726 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[209]} 0 0
[junit4] 2> 261729 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[210]} 0 0
[junit4] 2> 261733 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[211]} 0 0
[junit4] 2> 261736 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[212]} 0 0
[junit4] 2> 261739 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[213]} 0 0
[junit4] 2> 261743 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[214]} 0 1
[junit4] 2> 261746 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[215]} 0 1
[junit4] 2> 261749 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[216]} 0 0
[junit4] 2> 261752 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[217]} 0 0
[junit4] 2> 261755 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[218]} 0 0
[junit4] 2> 261758 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[219]} 0 0
[junit4] 2> 261761 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[220]} 0 0
[junit4] 2> 261765 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[221]} 0 1
[junit4] 2> 261768 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[222]} 0 1
[junit4] 2> 261770 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[223]} 0 0
[junit4] 2> 261773 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[224]} 0 0
[junit4] 2> 261776 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[225]} 0 0
[junit4] 2> 261779 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[226]} 0 0
[junit4] 2> 261782 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[227]} 0 0
[junit4] 2> 261785 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[228]} 0 0
[junit4] 2> 261788 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[229]} 0 0
[junit4] 2> 261791 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[230]} 0 0
[junit4] 2> 261794 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[231]} 0 0
[junit4] 2> 261797 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[232]} 0 0
[junit4] 2> 261800 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[233]} 0 0
[junit4] 2> 261803 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[234]} 0 0
[junit4] 2> 261806 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[235]} 0 0
[junit4] 2> 261810 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[236]} 0 1
[junit4] 2> 261813 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[237]} 0 1
[junit4] 2> 261815 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[238]} 0 0
[junit4] 2> 261818 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[239]} 0 0
[junit4] 2> 261821 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[240]} 0 0
[junit4] 2> 261825 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[241]} 0 1
[junit4] 2> 261827 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[242]} 0 0
[junit4] 2> 261830 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[243]} 0 0
[junit4] 2> 261833 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[244]} 0 0
[junit4] 2> 261836 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[245]} 0 0
[junit4] 2> 261839 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[246]} 0 0
[junit4] 2> 261842 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[247]} 0 0
[junit4] 2> 261845 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[248]} 0 0
[junit4] 2> 261848 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[249]} 0 0
[junit4] 2> 261851 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[250]} 0 0
[junit4] 2> 261854 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[251]} 0 0
[junit4] 2> 261857 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[252]} 0 0
[junit4] 2> 261860 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[253]} 0 0
[junit4] 2> 261864 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[254]} 0 1
[junit4] 2> 261867 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[255]} 0 1
[junit4] 2> 261870 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[256]} 0 0
[junit4] 2> 261873 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[257]} 0 0
[junit4] 2> 261876 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[258]} 0 0
[junit4] 2> 261879 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[259]} 0 0
[junit4] 2> 261882 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[260]} 0 0
[junit4] 2> 261885 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[261]} 0 0
[junit4] 2> 261888 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[262]} 0 0
[junit4] 2> 261892 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[263]} 0 1
[junit4] 2> 261894 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[264]} 0 0
[junit4] 2> 261897 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[265]} 0 0
[junit4] 2> 261900 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[266]} 0 0
[junit4] 2> 261903 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[267]} 0 0
[junit4] 2> 261906 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[268]} 0 0
[junit4] 2> 261909 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[269]} 0 0
[junit4] 2> 261912 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[270]} 0 0
[junit4] 2> 261915 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[271]} 0 0
[junit4] 2> 261919 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[272]} 0 1
[junit4] 2> 261921 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[273]} 0 0
[junit4] 2> 261925 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[274]} 0 1
[junit4] 2> 261927 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[275]} 0 0
[junit4] 2> 261930 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[276]} 0 0
[junit4] 2> 261933 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[277]} 0 0
[junit4] 2> 261937 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[278]} 0 1
[junit4] 2> 261939 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[279]} 0 0
[junit4] 2> 261942 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[280]} 0 0
[junit4] 2> 261945 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[281]} 0 0
[junit4] 2> 261948 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[282]} 0 0
[junit4] 2> 261951 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[283]} 0 0
[junit4] 2> 261954 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[284]} 0 0
[junit4] 2> 261957 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[285]} 0 0
[junit4] 2> 261960 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[286]} 0 0
[junit4] 2> 261963 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[287]} 0 0
[junit4] 2> 261966 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[288]} 0 0
[junit4] 2> 261969 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[289]} 0 0
[junit4] 2> 261972 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[290]} 0 0
[junit4] 2> 261976 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[291]} 0 1
[junit4] 2> 261978 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[292]} 0 0
[junit4] 2> 261981 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[293]} 0 0
[junit4] 2> 261984 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[294]} 0 0
[junit4] 2> 261987 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[295]} 0 0
[junit4] 2> 261990 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[296]} 0 0
[junit4] 2> 261993 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[297]} 0 0
[junit4] 2> 261996 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[298]} 0 0
[junit4] 2> 261999 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[299]} 0 0
[junit4] 2> 262002 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[300]} 0 0
[junit4] 2> 262005 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[301]} 0 0
[junit4] 2> 262008 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[302]} 0 0
[junit4] 2> 262012 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[303]} 0 1
[junit4] 2> 262014 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[304]} 0 0
[junit4] 2> 262017 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[305]} 0 0
[junit4] 2> 262020 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[306]} 0 0
[junit4] 2> 262024 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[307]} 0 1
[junit4] 2> 262026 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[308]} 0 0
[junit4] 2> 262029 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[309]} 0 0
[junit4] 2> 262032 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[310]} 0 0
[junit4] 2> 262035 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[311]} 0 0
[junit4] 2> 262038 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[312]} 0 0
[junit4] 2> 262041 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[313]} 0 0
[junit4] 2> 262045 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[314]} 0 1
[junit4] 2> 262048 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[315]} 0 0
[junit4] 2> 262051 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[316]} 0 0
[junit4] 2> 262054 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[317]} 0 0
[junit4] 2> 262057 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[318]} 0 0
[junit4] 2> 262060 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[319]} 0 0
[junit4] 2> 262063 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[320]} 0 0
[junit4] 2> 262067 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[321]} 0 1
[junit4] 2> 262070 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[322]} 0 0
[junit4] 2> 262073 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[323]} 0 0
[junit4] 2> 262077 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[324]} 0 1
[junit4] 2> 262079 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[325]} 0 0
[junit4] 2> 262082 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[326]} 0 0
[junit4] 2> 262085 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[327]} 0 0
[junit4] 2> 262088 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[328]} 0 0
[junit4] 2> 262091 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[329]} 0 0
[junit4] 2> 262094 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[330]} 0 0
[junit4] 2> 262097 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[331]} 0 0
[junit4] 2> 262100 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[332]} 0 0
[junit4] 2> 262103 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[333]} 0 0
[junit4] 2> 262106 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[334]} 0 0
[junit4] 2> 262110 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[335]} 0 1
[junit4] 2> 262112 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[336]} 0 0
[junit4] 2> 262116 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[337]} 0 0
[junit4] 2> 262118 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[338]} 0 0
[junit4] 2> 262121 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[339]} 0 0
[junit4] 2> 262124 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[340]} 0 0
[junit4] 2> 262127 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[341]} 0 0
[junit4] 2> 262130 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[342]} 0 0
[junit4] 2> 262134 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[343]} 0 1
[junit4] 2> 262136 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[344]} 0 0
[junit4] 2> 262139 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[345]} 0 0
[junit4] 2> 262142 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[346]} 0 0
[junit4] 2> 262145 T623 C500 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[347]} 0 0
[junit4]
[...truncated too long message...]
nit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2> Caused by: java.lang.RuntimeException: Interrupted while waiting for core reload to finish
[junit4] 2> at org.apache.solr.handler.SnapPuller.reloadCore(SnapPuller.java:721)
[junit4] 2> at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:473)
[junit4] 2> ... 10 more
[junit4] 2> Caused by: java.lang.InterruptedException
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:996)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1303)
[junit4] 2> at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:236)
[junit4] 2> at org.apache.solr.handler.SnapPuller.reloadCore(SnapPuller.java:718)
[junit4] 2> ... 11 more
[junit4] 2>
[junit4] 2> 937121 T1795 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 937121 T1795 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> ASYNC NEW_CORE C1232 name=collection1 org.apache.solr.core.SolrCore@461883b1
[junit4] 2> 937160 T1783 C1232 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&version=2&wt=javabin&q=*:*} hits=1 status=0 QTime=0
[junit4] 2> 937161 T619 oas.SolrTestCaseJ4.tearDown ###Ending doTestIndexAndConfigReplication
[junit4] 2> 937161 T619 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2012622067
[junit4] 2> 937162 T619 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@2933a4ea
[junit4] 2> 937162 T619 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 937163 T619 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 937163 T619 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 937163 T619 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 937164 T619 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 937164 T619 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 937164 T619 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062071/master/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062071/master/collection1/data;done=false>>]
[junit4] 2> 937165 T619 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062071/master/collection1/data
[junit4] 2> 937165 T619 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062071/master/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062071/master/collection1/data/index;done=false>>]
[junit4] 2> 937165 T619 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062071/master/collection1/data/index
[junit4] 2> 937166 T619 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 937218 T619 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2055639160
[junit4] 2> 937218 T619 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@461883b1
[junit4] 2> 937219 T619 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 937219 T619 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 937219 T619 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 937220 T619 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 937220 T619 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 937220 T619 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 937221 T619 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062322/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062322/slave/collection1/data;done=false>>]
[junit4] 2> 937221 T619 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062322/slave/collection1/data
[junit4] 2> 937221 T619 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062322/slave/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062322/slave/collection1/data/index;done=false>>]
[junit4] 2> 937221 T619 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1389994062322/slave/collection1/data/index
[junit4] 2> 937222 T619 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 937285 T619 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=mk_MK, timezone=Africa/Bujumbura
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=110813032,total=262602752
[junit4] 2> NOTE: All tests run in this JVM: [InfoHandlerTest, TestReversedWildcardFilterFactory, ExternalFileFieldSortTest, DOMUtilTest, BasicDistributedZkTest, SolrIndexSplitterTest, HdfsRecoveryZkTest, PrimitiveFieldTypeTest, TestGroupingSearch, TestQueryUtils, DirectUpdateHandlerOptimizeTest, MoreLikeThisHandlerTest, TestCollapseQParserPlugin, BinaryUpdateRequestHandlerTest, ZkCLITest, HdfsDirectoryTest, ReturnFieldsTest, DocValuesTest, TestSolrXml, TestReplicationHandler]
[junit4] Completed on J0 in 677.02s, 14 tests, 1 failure <<< FAILURES!
[...truncated 1010 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:460: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:433: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1304: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:937: There were test failures: 364 suites, 1596 tests, 1 failure, 32 ignored (4 assumptions)
Total time: 124 minutes 38 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure