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 2013/06/12 23:48:07 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4060 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4060/
1 tests failed.
REGRESSION: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:29281 returned non ok status:500, message:Server Error
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:29281 returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([553377D3887142A9:D4D5F9CBFF2E2295]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:228)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:150)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
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:601)
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:722)
Build Log:
[...truncated 10140 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4:junit4] 2> 2063355 T4424 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 2063362 T4424 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./solrtest-ShardSplitTest-1371073452424
[junit4:junit4] 2> 2063364 T4424 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 2063365 T4425 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 2063466 T4424 oasc.ZkTestServer.run start zk server on port:29274
[junit4:junit4] 2> 2063467 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2063472 T4431 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43e8fd24 name:ZooKeeperConnection Watcher:127.0.0.1:29274 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2063472 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2063473 T4424 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 2063493 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2063495 T4433 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21c64eef name:ZooKeeperConnection Watcher:127.0.0.1:29274/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2063495 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2063496 T4424 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 2063506 T4424 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 2063510 T4424 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 2063513 T4424 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 2063521 T4424 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 2063522 T4424 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 2063533 T4424 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 2063534 T4424 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 2063640 T4424 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 2063641 T4424 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 2063650 T4424 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 2063651 T4424 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 2063655 T4424 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 2063656 T4424 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 2063659 T4424 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 2063660 T4424 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 2063663 T4424 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 2063664 T4424 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 2063667 T4424 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 2063668 T4424 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 2063672 T4424 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 2063673 T4424 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 2063980 T4424 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2063989 T4424 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:?????
[junit4:junit4] 2> 2063990 T4424 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2063991 T4424 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2063992 T4424 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1371073452744
[junit4:junit4] 2> 2063992 T4424 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1371073452744/solr.xml
[junit4:junit4] 2> 2063993 T4424 oasc.CoreContainer.<init> New CoreContainer 797662199
[junit4:junit4] 2> 2063994 T4424 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1371073452744/'
[junit4:junit4] 2> 2063995 T4424 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1371073452744/'
[junit4:junit4] 2> 2064166 T4424 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2064167 T4424 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2064168 T4424 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2064168 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2064169 T4424 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2064170 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2064170 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2064171 T4424 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2064171 T4424 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2064172 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2064189 T4424 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2064190 T4424 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:29274/solr
[junit4:junit4] 2> 2064191 T4424 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2064192 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2064199 T4444 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@350c9617 name:ZooKeeperConnection Watcher:127.0.0.1:29274 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2064200 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2064204 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2064215 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2064218 T4446 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c413502 name:ZooKeeperConnection Watcher:127.0.0.1:29274/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2064218 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2064222 T4424 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 2064233 T4424 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 2064237 T4424 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 2064240 T4424 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29277_
[junit4:junit4] 2> 2064246 T4424 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29277_
[junit4:junit4] 2> 2064251 T4424 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 2064269 T4424 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 2064272 T4424 oasc.Overseer.start Overseer (id=89854669778583555-127.0.0.1:29277_-n_0000000000) starting
[junit4:junit4] 2> 2064286 T4424 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 2064297 T4448 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 2064298 T4424 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 2064301 T4424 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 2064303 T4424 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2064306 T4447 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 2064311 T4449 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2064311 T4449 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2065811 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2065812 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29277_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29277"}
[junit4:junit4] 2> 2065812 T4447 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 2065812 T4447 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 2065832 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 2066315 T4449 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1371073452744/collection1
[junit4:junit4] 2> 2066315 T4449 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 2066316 T4449 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2066317 T4449 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 2066318 T4449 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1371073452744/collection1/'
[junit4:junit4] 2> 2066320 T4449 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-controljetty-1371073452744/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2066321 T4449 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-controljetty-1371073452744/collection1/lib/README' to classloader
[junit4:junit4] 2> 2066380 T4449 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2066443 T4449 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2066546 T4449 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2066552 T4449 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2067226 T4449 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2067231 T4449 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2067233 T4449 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2067239 T4449 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2067263 T4449 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2067264 T4449 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1371073452744/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1371073452423/control/data/
[junit4:junit4] 2> 2067264 T4449 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@41e2771e
[junit4:junit4] 2> 2067265 T4449 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2067265 T4449 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/control/data
[junit4:junit4] 2> 2067266 T4449 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1371073452423/control/data/index/
[junit4:junit4] 2> 2067266 T4449 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1371073452423/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2067267 T4449 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/control/data/index
[junit4:junit4] 2> 2067272 T4449 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e68a302 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1a296340),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2067272 T4449 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2067276 T4449 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2067276 T4449 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2067277 T4449 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2067278 T4449 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2067278 T4449 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2067278 T4449 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2067279 T4449 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2067280 T4449 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2067280 T4449 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2067299 T4449 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2067307 T4449 oass.SolrIndexSearcher.<init> Opening Searcher@54601d57 main
[junit4:junit4] 2> 2067308 T4449 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1371073452423/control/data/tlog
[junit4:junit4] 2> 2067309 T4449 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2067309 T4449 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2067313 T4450 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@54601d57 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2067315 T4449 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2067315 T4449 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29277 collection:control_collection shard:shard1
[junit4:junit4] 2> 2067316 T4449 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2067345 T4449 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2067351 T4449 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2067352 T4449 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2067352 T4449 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:29277/collection1/
[junit4:junit4] 2> 2067353 T4449 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2067353 T4449 oasc.SyncStrategy.syncToMe http://127.0.0.1:29277/collection1/ has no replicas
[junit4:junit4] 2> 2067354 T4449 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:29277/collection1/
[junit4:junit4] 2> 2067354 T4449 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2068848 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2068871 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 2068918 T4449 oasc.ZkController.register We are http://127.0.0.1:29277/collection1/ and leader is http://127.0.0.1:29277/collection1/
[junit4:junit4] 2> 2068918 T4449 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29277
[junit4:junit4] 2> 2068919 T4449 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2068919 T4449 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2068919 T4449 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2068922 T4449 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2068923 T4424 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 2068924 T4424 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2068925 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2068943 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2068945 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2068947 T4453 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b581bef name:ZooKeeperConnection Watcher:127.0.0.1:29274/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2068948 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2068951 T4424 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2068954 T4424 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 2069246 T4424 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2069249 T4424 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:?????
[junit4:junit4] 2> 2069250 T4424 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2069251 T4424 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2069252 T4424 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1371073458015
[junit4:junit4] 2> 2069252 T4424 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1371073458015/solr.xml
[junit4:junit4] 2> 2069253 T4424 oasc.CoreContainer.<init> New CoreContainer 2063879364
[junit4:junit4] 2> 2069254 T4424 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1371073458015/'
[junit4:junit4] 2> 2069255 T4424 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1371073458015/'
[junit4:junit4] 2> 2069409 T4424 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2069410 T4424 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2069411 T4424 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2069411 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2069412 T4424 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2069413 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2069413 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2069414 T4424 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2069414 T4424 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2069415 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2069431 T4424 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2069432 T4424 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:29274/solr
[junit4:junit4] 2> 2069433 T4424 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2069434 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2069437 T4464 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d99819c name:ZooKeeperConnection Watcher:127.0.0.1:29274 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2069438 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2069453 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2069465 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2069467 T4466 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@30df2e33 name:ZooKeeperConnection Watcher:127.0.0.1:29274/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2069468 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2069479 T4424 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2070379 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2070380 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:29277__collection1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29277_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29277"}
[junit4:junit4] 2> 2070392 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 2070392 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 2070392 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 2070484 T4424 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29281_
[junit4:junit4] 2> 2070487 T4424 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29281_
[junit4:junit4] 2> 2070490 T4453 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2070490 T4446 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2070490 T4466 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2070491 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2070490 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2070491 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2070504 T4467 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2070505 T4467 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2071901 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2071902 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29281_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29281"}
[junit4:junit4] 2> 2071903 T4447 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 2071903 T4447 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 2071949 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2071949 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2071949 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2072511 T4467 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1371073458015/collection1
[junit4:junit4] 2> 2072511 T4467 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2072512 T4467 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2072513 T4467 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2072515 T4467 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1371073458015/collection1/'
[junit4:junit4] 2> 2072516 T4467 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty1-1371073458015/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2072517 T4467 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty1-1371073458015/collection1/lib/README' to classloader
[junit4:junit4] 2> 2072579 T4467 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2072647 T4467 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2072749 T4467 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2072756 T4467 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2073417 T4467 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2073422 T4467 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2073424 T4467 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2073430 T4467 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2073456 T4467 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2073457 T4467 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1371073458015/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty1/
[junit4:junit4] 2> 2073457 T4467 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@41e2771e
[junit4:junit4] 2> 2073458 T4467 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2073459 T4467 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty1
[junit4:junit4] 2> 2073459 T4467 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty1/index/
[junit4:junit4] 2> 2073460 T4467 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2073461 T4467 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty1/index
[junit4:junit4] 2> 2073465 T4467 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@11409e9b lockFactory=org.apache.lucene.store.NativeFSLockFactory@182cce06),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2073466 T4467 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2073470 T4467 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2073470 T4467 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2073471 T4467 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2073472 T4467 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2073472 T4467 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2073473 T4467 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2073473 T4467 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2073474 T4467 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2073475 T4467 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2073494 T4467 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2073502 T4467 oass.SolrIndexSearcher.<init> Opening Searcher@698f7557 main
[junit4:junit4] 2> 2073503 T4467 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty1/tlog
[junit4:junit4] 2> 2073504 T4467 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2073505 T4467 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2073510 T4468 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@698f7557 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2073512 T4467 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2073513 T4467 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29281 collection:collection1 shard:shard1
[junit4:junit4] 2> 2073514 T4467 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 2073547 T4467 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2073551 T4467 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2073551 T4467 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2073551 T4467 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:29281/collection1/
[junit4:junit4] 2> 2073552 T4467 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2073552 T4467 oasc.SyncStrategy.syncToMe http://127.0.0.1:29281/collection1/ has no replicas
[junit4:junit4] 2> 2073552 T4467 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:29281/collection1/
[junit4:junit4] 2> 2073553 T4467 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 2074958 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2074977 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2074977 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2074977 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2075007 T4467 oasc.ZkController.register We are http://127.0.0.1:29281/collection1/ and leader is http://127.0.0.1:29281/collection1/
[junit4:junit4] 2> 2075007 T4467 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29281
[junit4:junit4] 2> 2075008 T4467 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2075008 T4467 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2075008 T4467 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2075011 T4467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2075012 T4424 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 2075013 T4424 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2075014 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2075318 T4424 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2075322 T4424 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:?????
[junit4:junit4] 2> 2075323 T4424 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2075324 T4424 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2075325 T4424 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1371073464096
[junit4:junit4] 2> 2075325 T4424 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1371073464096/solr.xml
[junit4:junit4] 2> 2075326 T4424 oasc.CoreContainer.<init> New CoreContainer 1052678297
[junit4:junit4] 2> 2075327 T4424 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1371073464096/'
[junit4:junit4] 2> 2075328 T4424 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1371073464096/'
[junit4:junit4] 2> 2075474 T4424 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2075475 T4424 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2075476 T4424 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2075477 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2075477 T4424 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2075478 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2075478 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2075479 T4424 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2075480 T4424 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2075480 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2075498 T4424 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2075500 T4424 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:29274/solr
[junit4:junit4] 2> 2075500 T4424 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2075502 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2075505 T4480 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e4d47bd name:ZooKeeperConnection Watcher:127.0.0.1:29274 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2075506 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2075518 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2075529 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2075532 T4482 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d252476 name:ZooKeeperConnection Watcher:127.0.0.1:29274/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2075532 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2075545 T4424 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2076491 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2076492 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:29281__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29281_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29281"}
[junit4:junit4] 2> 2076552 T4424 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29284_
[junit4:junit4] 2> 2076554 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2076554 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2076554 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2076554 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 2076556 T4424 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29284_
[junit4:junit4] 2> 2076567 T4453 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2076567 T4446 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2076567 T4482 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2076567 T4466 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2076568 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2076568 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2076567 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2076568 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2076575 T4483 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2076575 T4483 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2078069 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2078070 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29284_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29284"}
[junit4:junit4] 2> 2078070 T4447 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 2078070 T4447 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 2078086 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2078086 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2078086 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2078086 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2078579 T4483 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1371073464096/collection1
[junit4:junit4] 2> 2078579 T4483 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2078580 T4483 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2078581 T4483 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2078582 T4483 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1371073464096/collection1/'
[junit4:junit4] 2> 2078584 T4483 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty2-1371073464096/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2078585 T4483 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty2-1371073464096/collection1/lib/README' to classloader
[junit4:junit4] 2> 2078648 T4483 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2078719 T4483 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2078821 T4483 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2078828 T4483 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2079438 T4483 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2079442 T4483 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2079445 T4483 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2079450 T4483 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2079473 T4483 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2079474 T4483 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1371073464096/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty2/
[junit4:junit4] 2> 2079475 T4483 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@41e2771e
[junit4:junit4] 2> 2079475 T4483 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2079476 T4483 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty2
[junit4:junit4] 2> 2079476 T4483 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty2/index/
[junit4:junit4] 2> 2079477 T4483 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2079479 T4483 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty2/index
[junit4:junit4] 2> 2079483 T4483 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6c4564eb lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c6cd84e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2079484 T4483 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2079488 T4483 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2079488 T4483 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2079489 T4483 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2079490 T4483 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2079491 T4483 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2079491 T4483 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2079492 T4483 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2079492 T4483 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2079493 T4483 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2079510 T4483 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2079518 T4483 oass.SolrIndexSearcher.<init> Opening Searcher@2a22d16d main
[junit4:junit4] 2> 2079519 T4483 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty2/tlog
[junit4:junit4] 2> 2079520 T4483 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2079521 T4483 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2079526 T4484 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2a22d16d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2079528 T4483 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2079528 T4483 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29284 collection:collection1 shard:shard2
[junit4:junit4] 2> 2079529 T4483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 2079547 T4483 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2079550 T4483 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2079550 T4483 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2079550 T4483 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:29284/collection1/
[junit4:junit4] 2> 2079551 T4483 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2079551 T4483 oasc.SyncStrategy.syncToMe http://127.0.0.1:29284/collection1/ has no replicas
[junit4:junit4] 2> 2079551 T4483 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:29284/collection1/
[junit4:junit4] 2> 2079552 T4483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 2079590 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2079599 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2079599 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2079599 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2079599 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2079608 T4483 oasc.ZkController.register We are http://127.0.0.1:29284/collection1/ and leader is http://127.0.0.1:29284/collection1/
[junit4:junit4] 2> 2079608 T4483 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29284
[junit4:junit4] 2> 2079608 T4483 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2079609 T4483 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2079609 T4483 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2079611 T4483 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2079612 T4424 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 2079613 T4424 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2079614 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2079920 T4424 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2079923 T4424 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:?????
[junit4:junit4] 2> 2079925 T4424 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2079925 T4424 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2079926 T4424 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1371073468693
[junit4:junit4] 2> 2079927 T4424 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1371073468693/solr.xml
[junit4:junit4] 2> 2079927 T4424 oasc.CoreContainer.<init> New CoreContainer 64387007
[junit4:junit4] 2> 2079928 T4424 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1371073468693/'
[junit4:junit4] 2> 2079929 T4424 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1371073468693/'
[junit4:junit4] 2> 2080087 T4424 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2080089 T4424 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2080089 T4424 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2080090 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2080090 T4424 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2080091 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2080092 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2080092 T4424 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2080093 T4424 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2080094 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2080113 T4424 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2080114 T4424 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:29274/solr
[junit4:junit4] 2> 2080115 T4424 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2080116 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2080119 T4496 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@caf2b70 name:ZooKeeperConnection Watcher:127.0.0.1:29274 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2080121 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2080135 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2080148 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2080150 T4498 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@465222d2 name:ZooKeeperConnection Watcher:127.0.0.1:29274/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2080151 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2080163 T4424 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2081105 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2081106 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:29284__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29284_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29284"}
[junit4:junit4] 2> 2081138 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2081138 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2081138 T4498 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2081138 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2081138 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2081193 T4424 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29287_
[junit4:junit4] 2> 2081213 T4424 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29287_
[junit4:junit4] 2> 2081217 T4453 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2081217 T4498 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2081217 T4466 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2081217 T4446 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2081217 T4482 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2081218 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2081218 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2081218 T4498 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2081217 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2081219 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2081281 T4499 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2081282 T4499 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2082697 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2082699 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29287_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29287"}
[junit4:junit4] 2> 2082699 T4447 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 2082699 T4447 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 2082726 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2082726 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2082726 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2082726 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2082726 T4498 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2083317 T4499 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1371073468693/collection1
[junit4:junit4] 2> 2083317 T4499 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2083318 T4499 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2083319 T4499 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2083320 T4499 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1371073468693/collection1/'
[junit4:junit4] 2> 2083322 T4499 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty3-1371073468693/collection1/lib/README' to classloader
[junit4:junit4] 2> 2083323 T4499 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty3-1371073468693/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2083387 T4499 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2083494 T4499 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2083596 T4499 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2083603 T4499 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2084248 T4499 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2084253 T4499 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2084255 T4499 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2084264 T4499 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2084288 T4499 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2084289 T4499 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1371073468693/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty3/
[junit4:junit4] 2> 2084289 T4499 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@41e2771e
[junit4:junit4] 2> 2084290 T4499 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2084291 T4499 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty3
[junit4:junit4] 2> 2084291 T4499 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty3/index/
[junit4:junit4] 2> 2084292 T4499 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2084293 T4499 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty3/index
[junit4:junit4] 2> 2084299 T4499 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@422733c0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1a3c31f1),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2084300 T4499 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2084304 T4499 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2084304 T4499 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2084305 T4499 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2084306 T4499 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2084307 T4499 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2084307 T4499 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2084308 T4499 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2084308 T4499 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2084309 T4499 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2084333 T4499 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2084343 T4499 oass.SolrIndexSearcher.<init> Opening Searcher@1b8ab79f main
[junit4:junit4] 2> 2084344 T4499 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty3/tlog
[junit4:junit4] 2> 2084346 T4499 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2084346 T4499 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2084350 T4500 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b8ab79f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2084353 T4499 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2084353 T4499 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29287 collection:collection1 shard:shard1
[junit4:junit4] 2> 2084393 T4499 oasc.ZkController.register We are http://127.0.0.1:29287/collection1/ and leader is http://127.0.0.1:29281/collection1/
[junit4:junit4] 2> 2084394 T4499 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29287
[junit4:junit4] 2> 2084394 T4499 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 2084395 T4499 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C2144 name=collection1 org.apache.solr.core.SolrCore@7c7b9a1b url=http://127.0.0.1:29287/collection1 node=127.0.0.1:29287_ C2144_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:29287_, base_url=http://127.0.0.1:29287}
[junit4:junit4] 2> 2084395 T4501 C2144 P29287 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 2084396 T4499 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2084396 T4501 C2144 P29287 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2084396 T4501 C2144 P29287 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 2084397 T4501 C2144 P29287 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2084397 T4424 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 2084398 T4424 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2084399 T4501 C2144 P29287 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2084399 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2084425 T4456 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:29287__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2084718 T4424 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2084721 T4424 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:?????
[junit4:junit4] 2> 2084722 T4424 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2084723 T4424 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2084724 T4424 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1371073473485
[junit4:junit4] 2> 2084724 T4424 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1371073473485/solr.xml
[junit4:junit4] 2> 2084725 T4424 oasc.CoreContainer.<init> New CoreContainer 1984419013
[junit4:junit4] 2> 2084726 T4424 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1371073473485/'
[junit4:junit4] 2> 2084726 T4424 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1371073473485/'
[junit4:junit4] 2> 2084869 T4424 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2084871 T4424 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2084871 T4424 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2084872 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2084872 T4424 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2084873 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2084874 T4424 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2084874 T4424 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2084875 T4424 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2084876 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2084893 T4424 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2084895 T4424 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:29274/solr
[junit4:junit4] 2> 2084895 T4424 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2084897 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2084900 T4513 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43739497 name:ZooKeeperConnection Watcher:127.0.0.1:29274 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2084901 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2084904 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2084917 T4424 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2084920 T4515 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2fa04ae5 name:ZooKeeperConnection Watcher:127.0.0.1:29274/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2084921 T4424 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2084932 T4424 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2085733 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2085735 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:29287__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29287_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29287"}
[junit4:junit4] 2> 2085777 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2085777 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2085777 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2085777 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2085777 T4498 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2085777 T4515 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2085937 T4424 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29291_
[junit4:junit4] 2> 2085941 T4424 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29291_
[junit4:junit4] 2> 2085944 T4515 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 2085945 T4453 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2085945 T4498 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2085945 T4482 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2085945 T4446 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2085945 T4466 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2085946 T4515 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2085946 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2085946 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2085945 T4498 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2085945 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2085946 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2085959 T4516 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2085959 T4516 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2086428 T4456 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:29287__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2086429 T4456 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:29287__collection1&state=recovering&nodeName=127.0.0.1:29287_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2004
[junit4:junit4] 2> 2087284 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2087286 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29291_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29291"}
[junit4:junit4] 2> 2087286 T4447 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 2087286 T4447 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 2087317 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2087317 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2087317 T4498 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2087317 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2087317 T4515 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2087317 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2087965 T4516 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1371073473485/collection1
[junit4:junit4] 2> 2087965 T4516 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2087966 T4516 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2087967 T4516 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2087969 T4516 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1371073473485/collection1/'
[junit4:junit4] 2> 2087970 T4516 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty4-1371073473485/collection1/lib/README' to classloader
[junit4:junit4] 2> 2087971 T4516 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty4-1371073473485/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2088030 T4516 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2088094 T4516 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2088196 T4516 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2088205 T4516 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> C2144_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:29287_, base_url=http://127.0.0.1:29287}
[junit4:junit4] 2> 2088430 T4501 C2144 P29287 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:29281/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2088430 T4501 C2144 P29287 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:29287 START replicas=[http://127.0.0.1:29281/collection1/] nUpdates=100
[junit4:junit4] 2> 2088431 T4501 C2144 P29287 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2088432 T4501 C2144 P29287 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 2088432 T4501 C2144 P29287 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 2088432 T4501 C2144 P29287 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 2088433 T4501 C2144 P29287 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2088433 T4501 C2144 P29287 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:29281/collection1/. core=collection1
[junit4:junit4] 2> 2088433 T4501 C2144 P29287 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C2145 name=collection1 org.apache.solr.core.SolrCore@7085cf39 url=http://127.0.0.1:29281/collection1 node=127.0.0.1:29281_ C2145_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:29281_, base_url=http://127.0.0.1:29281, leader=true}
[junit4:junit4] 2> 2088441 T4457 C2145 P29281 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 2088447 T4458 C2145 P29281 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2088451 T4458 C2145 P29281 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@11409e9b lockFactory=org.apache.lucene.store.NativeFSLockFactory@182cce06),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2088451 T4458 C2145 P29281 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2088452 T4458 C2145 P29281 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@11409e9b lockFactory=org.apache.lucene.store.NativeFSLockFactory@182cce06),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@11409e9b lockFactory=org.apache.lucene.store.NativeFSLockFactory@182cce06),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2088453 T4458 C2145 P29281 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2088453 T4458 C2145 P29281 oass.SolrIndexSearcher.<init> Opening Searcher@51e92563 realtime
[junit4:junit4] 2> 2088454 T4458 C2145 P29281 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2088454 T4458 C2145 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4] 2> ASYNC NEW_CORE C2146 name=collection1 org.apache.solr.core.SolrCore@7c7b9a1b url=http://127.0.0.1:29287/collection1 node=127.0.0.1:29287_ C2146_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:29287_, base_url=http://127.0.0.1:29287}
[junit4:junit4] 2> 2088490 T4501 C2146 P29287 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2088491 T4501 C2146 P29287 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> ASYNC NEW_CORE C2147 name=collection1 org.apache.solr.core.SolrCore@7085cf39 url=http://127.0.0.1:29281/collection1 node=127.0.0.1:29281_ C2147_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:29281_, base_url=http://127.0.0.1:29281, leader=true}
[junit4:junit4] 2> 2088495 T4459 C2147 P29281 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2088495 T4459 C2147 P29281 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=3
[junit4:junit4] 2> 2088496 T4501 C2146 P29287 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2088497 T4501 C2146 P29287 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2088497 T4501 C2146 P29287 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2088499 T4459 C2147 P29281 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 2088500 T4501 C2146 P29287 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2088501 T4501 C2146 P29287 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty3/index.20130612234437561
[junit4:junit4] 2> 2088501 T4501 C2146 P29287 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@5ea9256a lockFactory=org.apache.lucene.store.NativeFSLockFactory@28d0a091) fullCopy=false
[junit4:junit4] 2> 2088504 T4459 C2147 P29281 oasc.SolrCore.execute [collection1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 2088506 T4501 C2146 P29287 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2088507 T4501 C2146 P29287 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2088507 T4501 C2146 P29287 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 2088509 T4501 C2146 P29287 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@422733c0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1a3c31f1),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@422733c0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1a3c31f1),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2088510 T4501 C2146 P29287 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2088510 T4501 C2146 P29287 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2088510 T4501 C2146 P29287 oass.SolrIndexSearcher.<init> Opening Searcher@7df973c2 main
[junit4:junit4] 2> 2088512 T4500 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7df973c2 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2088512 T4501 C2146 P29287 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty3/index.20130612234437561 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty3/index.20130612234437561;done=true>>]
[junit4:junit4] 2> 2088513 T4501 C2146 P29287 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty3/index.20130612234437561
[junit4:junit4] 2> 2088513 T4501 C2146 P29287 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty3/index.20130612234437561
[junit4:junit4] 2> 2088513 T4501 C2146 P29287 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 2088513 T4501 C2146 P29287 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 2088514 T4501 C2146 P29287 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2088514 T4501 C2146 P29287 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2088516 T4501 C2146 P29287 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 2088830 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2088831 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:29287__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29287_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29287"}
[junit4:junit4] 2> 2088845 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2088845 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2088845 T4498 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2088845 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2088845 T4515 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2088845 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2088857 T4516 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2088862 T4516 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2088864 T4516 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2088870 T4516 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2088893 T4516 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2088894 T4516 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1371073473485/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/
[junit4:junit4] 2> 2088894 T4516 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@41e2771e
[junit4:junit4] 2> 2088895 T4516 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2088896 T4516 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4
[junit4:junit4] 2> 2088896 T4516 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/index/
[junit4:junit4] 2> 2088897 T4516 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2088898 T4516 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/index
[junit4:junit4] 2> 2088902 T4516 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2742d9a2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@225bcc23),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2088902 T4516 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2088907 T4516 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2088907 T4516 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2088908 T4516 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2088909 T4516 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2088910 T4516 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2088910 T4516 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2088911 T4516 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2088911 T4516 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2088912 T4516 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2088936 T4516 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2088948 T4516 oass.SolrIndexSearcher.<init> Opening Searcher@9a52784 main
[junit4:junit4] 2> 2088949 T4516 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/tlog
[junit4:junit4] 2> 2088950 T4516 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2088950 T4516 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2088955 T4519 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9a52784 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2088958 T4516 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2088958 T4516 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29291 collection:collection1 shard:shard2
[junit4:junit4] 2> 2088962 T4516 oasc.ZkController.register We are http://127.0.0.1:29291/collection1/ and leader is http://127.0.0.1:29284/collection1/
[junit4:junit4] 2> 2088962 T4516 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29291
[junit4:junit4] 2> 2088962 T4516 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 2088963 T4516 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C2148 name=collection1 org.apache.solr.core.SolrCore@10cdf32a url=http://127.0.0.1:29291/collection1 node=127.0.0.1:29291_ C2148_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:29291_, base_url=http://127.0.0.1:29291}
[junit4:junit4] 2> 2088963 T4520 C2148 P29291 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 2088964 T4516 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2088964 T4520 C2148 P29291 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2088964 T4520 C2148 P29291 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 2088965 T4520 C2148 P29291 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2088965 T4424 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 2088966 T4424 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2088967 T4424 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2088967 T4520 C2148 P29291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2088993 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2088994 T4472 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:29291__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2088995 T4424 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 2088996 T4424 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 2088997 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2090000 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2090351 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2090353 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:29291__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29291_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29291"}
[junit4:junit4] 2> 2090369 T4515 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2090369 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2090369 T4498 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2090369 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2090369 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2090369 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2090999 T4472 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:29291__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2091000 T4472 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:29291__collection1&state=recovering&nodeName=127.0.0.1:29291_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2006
[junit4:junit4] 2> 2091003 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2092008 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C2148_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:29291_, base_url=http://127.0.0.1:29291}
[junit4:junit4] 2> 2093003 T4520 C2148 P29291 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:29284/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2093003 T4520 C2148 P29291 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:29291 START replicas=[http://127.0.0.1:29284/collection1/] nUpdates=100
[junit4:junit4] 2> 2093004 T4520 C2148 P29291 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2093005 T4520 C2148 P29291 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 2093005 T4520 C2148 P29291 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 2093005 T4520 C2148 P29291 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 2093005 T4520 C2148 P29291 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2093006 T4520 C2148 P29291 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:29284/collection1/. core=collection1
[junit4:junit4] 2> 2093007 T4520 C2148 P29291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2093011 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C2149 name=collection1 org.apache.solr.core.SolrCore@3fcd4b9f url=http://127.0.0.1:29284/collection1 node=127.0.0.1:29284_ C2149_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:29284_, base_url=http://127.0.0.1:29284, leader=true}
[junit4:junit4] 2> 2093015 T4473 C2149 P29284 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 2093020 T4474 C2149 P29284 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2093023 T4474 C2149 P29284 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6c4564eb lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c6cd84e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2093023 T4474 C2149 P29284 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2093024 T4474 C2149 P29284 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6c4564eb lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c6cd84e),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6c4564eb lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c6cd84e),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2093025 T4474 C2149 P29284 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2093025 T4474 C2149 P29284 oass.SolrIndexSearcher.<init> Opening Searcher@34a8d5c8 realtime
[junit4:junit4] 2> 2093026 T4474 C2149 P29284 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2093026 T4474 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 6
[junit4:junit4] 2> 2093027 T4520 C2148 P29291 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2093028 T4520 C2148 P29291 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2093029 T4475 C2149 P29284 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2093030 T4475 C2149 P29284 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 2093031 T4520 C2148 P29291 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2093031 T4520 C2148 P29291 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2093031 T4520 C2148 P29291 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2093033 T4475 C2149 P29284 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 2093034 T4520 C2148 P29291 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2093035 T4520 C2148 P29291 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/index.20130612234442095
[junit4:junit4] 2> 2093035 T4520 C2148 P29291 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@15e4ad43 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3eafce3d) fullCopy=false
[junit4:junit4] 2> 2093038 T4475 C2149 P29284 oasc.SolrCore.execute [collection1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 2093039 T4520 C2148 P29291 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2093040 T4520 C2148 P29291 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2093040 T4520 C2148 P29291 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 2093042 T4520 C2148 P29291 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2742d9a2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@225bcc23),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2742d9a2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@225bcc23),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2093042 T4520 C2148 P29291 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2093043 T4520 C2148 P29291 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2093043 T4520 C2148 P29291 oass.SolrIndexSearcher.<init> Opening Searcher@6e53ef8 main
[junit4:junit4] 2> 2093044 T4519 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6e53ef8 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2093045 T4520 C2148 P29291 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/index.20130612234442095 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/index.20130612234442095;done=true>>]
[junit4:junit4] 2> 2093045 T4520 C2148 P29291 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/index.20130612234442095
[junit4:junit4] 2> 2093046 T4520 C2148 P29291 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/index.20130612234442095
[junit4:junit4] 2> 2093046 T4520 C2148 P29291 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 2093046 T4520 C2148 P29291 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 2093046 T4520 C2148 P29291 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2093047 T4520 C2148 P29291 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2093049 T4520 C2148 P29291 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 2093377 T4447 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2093378 T4447 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:29291__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:29291_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29291"}
[junit4:junit4] 2> 2093396 T4453 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2093396 T4466 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2093396 T4498 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2093396 T4515 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2093396 T4446 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2093396 T4482 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 2094014 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2094016 T4424 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C2150 name=collection1 org.apache.solr.core.SolrCore@37b25513 url=http://127.0.0.1:29277/collection1 node=127.0.0.1:29277_ C2150_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:29277_, base_url=http://127.0.0.1:29277, leader=true}
[junit4:junit4] 2> 2094022 T4436 C2150 P29277 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2094024 T4436 C2150 P29277 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e68a302 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1a296340),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2094025 T4436 C2150 P29277 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2094025 T4436 C2150 P29277 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e68a302 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1a296340),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e68a302 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1a296340),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2094025 T4436 C2150 P29277 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2094026 T4436 C2150 P29277 oass.SolrIndexSearcher.<init> Opening Searcher@4d41c716 main
[junit4:junit4] 2> 2094026 T4436 C2150 P29277 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2094027 T4450 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4d41c716 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2094028 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 6
[junit4:junit4] 2> 2094036 T4460 C2147 P29281 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2094039 T4460 C2147 P29281 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@11409e9b lockFactory=org.apache.lucene.store.NativeFSLockFactory@182cce06),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@11409e9b lockFactory=org.apache.lucene.store.NativeFSLockFactory@182cce06),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2094039 T4460 C2147 P29281 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2094040 T4460 C2147 P29281 oass.SolrIndexSearcher.<init> Opening Searcher@2663bd4d main
[junit4:junit4] 2> 2094041 T4460 C2147 P29281 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2094041 T4468 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2663bd4d main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2094042 T4460 C2147 P29281 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:29287/collection1/, StdNode: http://127.0.0.1:29284/collection1/, StdNode: http://127.0.0.1:29291/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> 2094045 T4476 C2149 P29284 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2094046 T4476 C2149 P29284 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6c4564eb lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c6cd84e),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6c4564eb lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c6cd84e),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2094046 T4476 C2149 P29284 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2094047 T4476 C2149 P29284 oass.SolrIndexSearcher.<init> Opening Searcher@f0127c main
[junit4:junit4] 2> 2094048 T4476 C2149 P29284 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2094048 T4484 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f0127c main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2094049 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 4
[junit4:junit4] 2> C2148_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:29291_, base_url=http://127.0.0.1:29291}
[junit4:junit4] 2> 2094050 T4505 C2148 P29291 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2094051 T4505 C2148 P29291 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2742d9a2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@225bcc23),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2742d9a2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@225bcc23),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2094051 T4505 C2148 P29291 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2094052 T4505 C2148 P29291 oass.SolrIndexSearcher.<init> Opening Searcher@2a6899c6 main
[junit4:junit4] 2> 2094052 T4505 C2148 P29291 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> C2146_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:29287_, base_url=http://127.0.0.1:29287}
[junit4:junit4] 2> 2094052 T4488 C2146 P29287 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2094053 T4519 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2a6899c6 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2094053 T4488 C2146 P29287 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@422733c0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1a3c31f1),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@422733c0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1a3c31f1),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2094054 T4505 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 4
[junit4:junit4] 2> 2094054 T4488 C2146 P29287 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2094055 T4488 C2146 P29287 oass.SolrIndexSearcher.<init> Opening Searcher@6c88ab14 main
[junit4:junit4] 2> 2094056 T4488 C2146 P29287 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2094056 T4500 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6c88ab14 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2094057 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> 2094057 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 21
[junit4:junit4] 2> 2094059 T4424 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2094061 T4461 C2147 P29281 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 2094063 T4489 C2146 P29287 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 2094064 T4477 C2149 P29284 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 2094066 T4506 C2148 P29291 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=1
[junit4:junit4] 2> 2096071 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1437674750744723456)} 0 2
[junit4:junit4] 2> 2096081 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1437674750751014912&update.from=http://127.0.0.1:29281/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1437674750751014912)} 0 1
[junit4:junit4] 2> 2096087 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1437674750756257792&update.from=http://127.0.0.1:29284/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1437674750756257792)} 0 2
[junit4:junit4] 2> 2096088 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1437674750756257792)} 0 7
[junit4:junit4] 2> 2096089 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1437674750751014912)} 0 13
[junit4:junit4] 2> 2096095 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!0 (1437674750768840704)]} 0 2
[junit4:junit4] 2> 2096100 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!0 (1437674750773035008)]} 0 1
[junit4:junit4] 2> 2096101 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!0 (1437674750773035008)]} 0 4
[junit4:junit4] 2> 2096104 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!1 (1437674750779326464)]} 0 1
[junit4:junit4] 2> 2096112 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!1 (1437674750784569344)]} 0 1
[junit4:junit4] 2> 2096113 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[b!1 (1437674750784569344)]} 0 6
[junit4:junit4] 2> 2096113 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!1]} 0 7
[junit4:junit4] 2> 2096116 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!2 (1437674750792957952)]} 0 0
[junit4:junit4] 2> 2096125 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!2 (1437674750799249408)]} 0 0
[junit4:junit4] 2> 2096126 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[c!2 (1437674750799249408)]} 0 4
[junit4:junit4] 2> 2096127 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!2]} 0 8
[junit4:junit4] 2> 2096129 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!3 (1437674750806589440)]} 0 0
[junit4:junit4] 2> 2096136 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!3 (1437674750810783744)]} 0 0
[junit4:junit4] 2> 2096137 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!3 (1437674750810783744)]} 0 4
[junit4:junit4] 2> 2096141 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!4 (1437674750819172352)]} 0 0
[junit4:junit4] 2> 2096148 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!4 (1437674750822318080)]} 0 1
[junit4:junit4] 2> 2096149 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!4 (1437674750822318080)]} 0 5
[junit4:junit4] 2> 2096151 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!5 (1437674750829658112)]} 0 0
[junit4:junit4] 2> 2096157 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!5 (1437674750833852416)]} 0 0
[junit4:junit4] 2> 2096158 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!5 (1437674750833852416)]} 0 3
[junit4:junit4] 2> 2096162 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!6 (1437674750841192448)]} 0 0
[junit4:junit4] 2> 2096170 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!6 (1437674750846435328)]} 0 0
[junit4:junit4] 2> 2096171 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[g!6 (1437674750846435328)]} 0 4
[junit4:junit4] 2> 2096172 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!6]} 0 7
[junit4:junit4] 2> 2096174 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!7 (1437674750853775360)]} 0 0
[junit4:junit4] 2> 2096179 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!7 (1437674750856921088)]} 0 0
[junit4:junit4] 2> 2096180 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!7 (1437674750856921088)]} 0 3
[junit4:junit4] 2> 2096183 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!8 (1437674750863212544)]} 0 0
[junit4:junit4] 2> 2096192 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!8 (1437674750869504000)]} 0 0
[junit4:junit4] 2> 2096193 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[i!8 (1437674750869504000)]} 0 4
[junit4:junit4] 2> 2096194 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!8]} 0 7
[junit4:junit4] 2> 2096198 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!9 (1437674750878941184)]} 0 0
[junit4:junit4] 2> 2096203 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!9 (1437674750883135488)]} 0 0
[junit4:junit4] 2> 2096204 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!9 (1437674750883135488)]} 0 2
[junit4:junit4] 2> 2096208 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!10 (1437674750889426944)]} 0 0
[junit4:junit4] 2> 2096214 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!10 (1437674750892572672)]} 0 0
[junit4:junit4] 2> 2096215 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!10 (1437674750892572672)]} 0 4
[junit4:junit4] 2> 2096218 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!11 (1437674750899912704)]} 0 0
[junit4:junit4] 2> 2096227 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!11 (1437674750906204160)]} 0 0
[junit4:junit4] 2> 2096228 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[l!11 (1437674750906204160)]} 0 4
[junit4:junit4] 2> 2096229 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!11]} 0 8
[junit4:junit4] 2> 2096231 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!12 (1437674750913544192)]} 0 0
[junit4:junit4] 2> 2096237 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!12 (1437674750916689920)]} 0 0
[junit4:junit4] 2> 2096238 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!12 (1437674750916689920)]} 0 4
[junit4:junit4] 2> 2096241 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!13 (1437674750924029952)]} 0 0
[junit4:junit4] 2> 2096249 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[n!13 (1437674750929272832)]} 0 0
[junit4:junit4] 2> 2096250 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[n!13 (1437674750929272832)]} 0 4
[junit4:junit4] 2> 2096251 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!13]} 0 7
[junit4:junit4] 2> 2096254 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!14 (1437674750937661440)]} 0 0
[junit4:junit4] 2> 2096260 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[o!14 (1437674750941855744)]} 0 0
[junit4:junit4] 2> 2096261 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!14 (1437674750941855744)]} 0 3
[junit4:junit4] 2> 2096264 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!15 (1437674750948147200)]} 0 0
[junit4:junit4] 2> 2096272 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[p!15 (1437674750953390080)]} 0 0
[junit4:junit4] 2> 2096273 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[p!15 (1437674750953390080)]} 0 4
[junit4:junit4] 2> 2096274 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!15]} 0 7
[junit4:junit4] 2> 2096277 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!16 (1437674750961778688)]} 0 0
[junit4:junit4] 2> 2096285 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[q!16 (1437674750967021568)]} 0 0
[junit4:junit4] 2> 2096286 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[q!16 (1437674750967021568)]} 0 4
[junit4:junit4] 2> 2096287 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!16]} 0 7
[junit4:junit4] 2> 2096290 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!17 (1437674750975410176)]} 0 0
[junit4:junit4] 2> 2096300 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[r!17 (1437674750982750208)]} 0 0
[junit4:junit4] 2> 2096301 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[r!17 (1437674750982750208)]} 0 4
[junit4:junit4] 2> 2096302 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!17]} 0 8
[junit4:junit4] 2> 2096304 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!18 (1437674750990090240)]} 0 0
[junit4:junit4] 2> 2096313 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[s!18 (1437674750996381696)]} 0 0
[junit4:junit4] 2> 2096314 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[s!18 (1437674750996381696)]} 0 4
[junit4:junit4] 2> 2096315 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!18]} 0 7
[junit4:junit4] 2> 2096318 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!19 (1437674751004770304)]} 0 0
[junit4:junit4] 2> 2096325 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[t!19 (1437674751010013184)]} 0 0
[junit4:junit4] 2> 2096326 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[t!19 (1437674751010013184)]} 0 3
[junit4:junit4] 2> 2096327 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!19]} 0 6
[junit4:junit4] 2> 2096330 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!20 (1437674751017353216)]} 0 0
[junit4:junit4] 2> 2096336 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[u!20 (1437674751020498944)]} 0 1
[junit4:junit4] 2> 2096336 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!20 (1437674751020498944)]} 0 3
[junit4:junit4] 2> 2096339 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[v!21 (1437674751026790400)]} 0 0
[junit4:junit4] 2> 2096346 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[v!21 (1437674751030984704)]} 0 0
[junit4:junit4] 2> 2096347 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[v!21 (1437674751030984704)]} 0 4
[junit4:junit4] 2> 2096351 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[w!22 (1437674751039373312)]} 0 0
[junit4:junit4] 2> 2096360 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[w!22 (1437674751044616192)]} 0 0
[junit4:junit4] 2> 2096361 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[w!22 (1437674751044616192)]} 0 5
[junit4:junit4] 2> 2096362 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[w!22]} 0 7
[junit4:junit4] 2> 2096365 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[x!23 (1437674751054053376)]} 0 0
[junit4:junit4] 2> 2096371 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[x!23 (1437674751058247680)]} 0 0
[junit4:junit4] 2> 2096372 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[x!23 (1437674751058247680)]} 0 3
[junit4:junit4] 2> 2096376 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[y!24 (1437674751065587712)]} 0 0
[junit4:junit4] 2> 2096382 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[y!24 (1437674751068733440)]} 0 0
[junit4:junit4] 2> 2096383 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[y!24 (1437674751068733440)]} 0 4
[junit4:junit4] 2> 2096386 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[z!25 (1437674751076073472)]} 0 0
[junit4:junit4] 2> 2096391 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[z!25 (1437674751079219200)]} 0 0
[junit4:junit4] 2> 2096392 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[z!25 (1437674751079219200)]} 0 3
[junit4:junit4] 2> 2096396 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!26 (1437674751086559232)]} 0 0
[junit4:junit4] 2> 2096404 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!26 (1437674751091802112)]} 0 0
[junit4:junit4] 2> 2096405 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[a!26 (1437674751091802112)]} 0 4
[junit4:junit4] 2> 2096406 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!26]} 0 7
[junit4:junit4] 2> 2096409 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!27 (1437674751100190720)]} 0 0
[junit4:junit4] 2> 2096416 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!27 (1437674751105433600)]} 0 0
[junit4:junit4] 2> 2096417 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[b!27 (1437674751105433600)]} 0 3
[junit4:junit4] 2> 2096418 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!27]} 0 6
[junit4:junit4] 2> 2096423 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!28 (1437674751113822208)]} 0 1
[junit4:junit4] 2> 2096428 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!28 (1437674751118016512)]} 0 0
[junit4:junit4] 2> 2096429 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!28 (1437674751118016512)]} 0 3
[junit4:junit4] 2> 2096432 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!29 (1437674751124307968)]} 0 0
[junit4:junit4] 2> 2096440 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!29 (1437674751129550848)]} 0 0
[junit4:junit4] 2> 2096441 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[d!29 (1437674751129550848)]} 0 4
[junit4:junit4] 2> 2096442 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!29]} 0 7
[junit4:junit4] 2> 2096446 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!30 (1437674751138988032)]} 0 0
[junit4:junit4] 2> 2096455 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!30 (1437674751146328064)]} 0 0
[junit4:junit4] 2> 2096456 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[e!30 (1437674751146328064)]} 0 3
[junit4:junit4] 2> 2096457 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!30]} 0 7
[junit4:junit4] 2> 2096460 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!31 (1437674751153668096)]} 0 0
[junit4:junit4] 2> 2096465 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!31 (1437674751157862400)]} 0 0
[junit4:junit4] 2> 2096466 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!31 (1437674751157862400)]} 0 2
[junit4:junit4] 2> 2096470 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!32 (1437674751164153856)]} 0 0
[junit4:junit4] 2> 2096479 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!32 (1437674751170445312)]} 0 0
[junit4:junit4] 2> 2096480 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[g!32 (1437674751170445312)]} 0 4
[junit4:junit4] 2> 2096481 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!32]} 0 7
[junit4:junit4] 2> 2096484 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!33 (1437674751178833920)]} 0 0
[junit4:junit4] 2> 2096491 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!33 (1437674751183028224)]} 0 0
[junit4:junit4] 2> 2096492 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!33 (1437674751183028224)]} 0 4
[junit4:junit4] 2> 2096496 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!34 (1437674751191416832)]} 0 0
[junit4:junit4] 2> 2096505 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!34 (1437674751197708288)]} 0 0
[junit4:junit4] 2> 2096506 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[i!34 (1437674751197708288)]} 0 4
[junit4:junit4] 2> 2096507 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!34]} 0 7
[junit4:junit4] 2> 2096511 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!35 (1437674751207145472)]} 0 0
[junit4:junit4] 2> 2096518 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!35 (1437674751211339776)]} 0 0
[junit4:junit4] 2> 2096519 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!35 (1437674751211339776)]} 0 4
[junit4:junit4] 2> 2096522 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!36 (1437674751218679808)]} 0 0
[junit4:junit4] 2> 2096529 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!36 (1437674751223922688)]} 0 0
[junit4:junit4] 2> 2096530 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[k!36 (1437674751223922688)]} 0 3
[junit4:junit4] 2> 2096531 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!36]} 0 6
[junit4:junit4] 2> 2096533 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!37 (1437674751230214144)]} 0 0
[junit4:junit4] 2> 2096541 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!37 (1437674751235457024)]} 0 0
[junit4:junit4] 2> 2096542 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[l!37 (1437674751235457024)]} 0 4
[junit4:junit4] 2> 2096543 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!37]} 0 7
[junit4:junit4] 2> 2096546 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!38 (1437674751243845632)]} 0 0
[junit4:junit4] 2> 2096554 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!38 (1437674751249088512)]} 0 0
[junit4:junit4] 2> 2096555 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[m!38 (1437674751249088512)]} 0 4
[junit4:junit4] 2> 2096556 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!38]} 0 7
[junit4:junit4] 2> 2096560 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!39 (1437674751258525696)]} 0 0
[junit4:junit4] 2> 2096568 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[n!39 (1437674751264817152)]} 0 0
[junit4:junit4] 2> 2096569 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[n!39 (1437674751264817152)]} 0 3
[junit4:junit4] 2> 2096570 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!39]} 0 7
[junit4:junit4] 2> 2096575 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!40 (1437674751272157184)]} 0 2
[junit4:junit4] 2> 2096580 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[o!40 (1437674751277400064)]} 0 0
[junit4:junit4] 2> 2096581 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!40 (1437674751277400064)]} 0 3
[junit4:junit4] 2> 2096584 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!41 (1437674751283691520)]} 0 0
[junit4:junit4] 2> 2096591 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[p!41 (1437674751287885824)]} 0 0
[junit4:junit4] 2> 2096592 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!41 (1437674751287885824)]} 0 4
[junit4:junit4] 2> 2096596 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!42 (1437674751296274432)]} 0 0
[junit4:junit4] 2> 2096603 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[q!42 (1437674751300468736)]} 0 0
[junit4:junit4] 2> 2096604 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!42 (1437674751300468736)]} 0 4
[junit4:junit4] 2> 2096608 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!43 (1437674751308857344)]} 0 0
[junit4:junit4] 2> 2096615 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[r!43 (1437674751313051648)]} 0 0
[junit4:junit4] 2> 2096616 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!43 (1437674751313051648)]} 0 4
[junit4:junit4] 2> 2096619 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!44 (1437674751320391680)]} 0 0
[junit4:junit4] 2> 2096628 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[s!44 (1437674751326683136)]} 0 0
[junit4:junit4] 2> 2096629 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[s!44 (1437674751326683136)]} 0 4
[junit4:junit4] 2> 2096630 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!44]} 0 8
[junit4:junit4] 2> 2096632 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!45 (1437674751334023168)]} 0 0
[junit4:junit4] 2> 2096638 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[t!45 (1437674751337168896)]} 0 0
[junit4:junit4] 2> 2096639 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!45 (1437674751337168896)]} 0 4
[junit4:junit4] 2> 2096642 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!46 (1437674751344508928)]} 0 0
[junit4:junit4] 2> 2096651 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[u!46 (1437674751350800384)]} 0 0
[junit4:junit4] 2> 2096652 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[u!46 (1437674751350800384)]} 0 4
[junit4:junit4] 2> 2096653 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!46]} 0 8
[junit4:junit4] 2> 2096656 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[v!47 (1437674751359188992)]} 0 0
[junit4:junit4] 2> 2096663 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[v!47 (1437674751365480448)]} 0 0
[junit4:junit4] 2> 2096664 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[v!47 (1437674751365480448)]} 0 2
[junit4:junit4] 2> 2096665 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[v!47]} 0 6
[junit4:junit4] 2> 2096667 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[w!48 (1437674751370723328)]} 0 0
[junit4:junit4] 2> 2096675 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[w!48 (1437674751377014784)]} 0 0
[junit4:junit4] 2> 2096676 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[w!48 (1437674751377014784)]} 0 3
[junit4:junit4] 2> 2096677 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[w!48]} 0 7
[junit4:junit4] 2> 2096680 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[x!49 (1437674751384354816)]} 0 0
[junit4:junit4] 2> 2096686 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[x!49 (1437674751387500544)]} 0 0
[junit4:junit4] 2> 2096687 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[x!49 (1437674751387500544)]} 0 4
[junit4:junit4] 2> 2096690 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[y!50 (1437674751394840576)]} 0 0
[junit4:junit4] 2> 2096697 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[y!50 (1437674751400083456)]} 0 0
[junit4:junit4] 2> 2096698 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[y!50 (1437674751400083456)]} 0 3
[junit4:junit4] 2> 2096699 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[y!50]} 0 6
[junit4:junit4] 2> 2096701 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[z!51 (1437674751406374912)]} 0 0
[junit4:junit4] 2> 2096710 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[z!51 (1437674751412666368)]} 0 0
[junit4:junit4] 2> 2096711 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[z!51 (1437674751412666368)]} 0 4
[junit4:junit4] 2> 2096712 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[z!51]} 0 8
[junit4:junit4] 2> 2096715 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!52 (1437674751421054976)]} 0 0
[junit4:junit4] 2> 2096722 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!52 (1437674751426297856)]} 0 0
[junit4:junit4] 2> 2096723 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[a!52 (1437674751426297856)]} 0 3
[junit4:junit4] 2> 2096724 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!52]} 0 7
[junit4:junit4] 2> 2096727 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!53 (1437674751433637888)]} 0 0
[junit4:junit4] 2> 2096732 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!53 (1437674751436783616)]} 0 0
[junit4:junit4] 2> 2096733 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!53 (1437674751436783616)]} 0 3
[junit4:junit4] 2> 2096736 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!54 (1437674751443075072)]} 0 0
[junit4:junit4] 2> 2096741 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!54 (1437674751446220800)]} 0 0
[junit4:junit4] 2> 2096742 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!54 (1437674751446220800)]} 0 3
[junit4:junit4] 2> 2096745 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!55 (1437674751452512256)]} 0 0
[junit4:junit4] 2> 2096753 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!55 (1437674751458803712)]} 0 0
[junit4:junit4] 2> 2096754 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[d!55 (1437674751458803712)]} 0 3
[junit4:junit4] 2> 2096755 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!55]} 0 6
[junit4:junit4] 2> 2096758 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!56 (1437674751466143744)]} 0 0
[junit4:junit4] 2> 2096763 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!56 (1437674751469289472)]} 0 0
[junit4:junit4] 2> 2096764 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!56 (1437674751469289472)]} 0 3
[junit4:junit4] 2> 2096768 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!57 (1437674751476629504)]} 0 0
[junit4:junit4] 2> 2096773 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!57 (1437674751479775232)]} 0 0
[junit4:junit4] 2> 2096774 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!57 (1437674751479775232)]} 0 3
[junit4:junit4] 2> 2096778 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!58 (1437674751487115264)]} 0 0
[junit4:junit4] 2> 2096787 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!58 (1437674751493406720)]} 0 0
[junit4:junit4] 2> 2096788 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[g!58 (1437674751493406720)]} 0 4
[junit4:junit4] 2> 2096789 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!58]} 0 8
[junit4:junit4] 2> 2096792 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!59 (1437674751501795328)]} 0 0
[junit4:junit4] 2> 2096799 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!59 (1437674751507038208)]} 0 0
[junit4:junit4] 2> 2096800 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[h!59 (1437674751507038208)]} 0 3
[junit4:junit4] 2> 2096801 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!59]} 0 6
[junit4:junit4] 2> 2096804 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!60 (1437674751514378240)]} 0 0
[junit4:junit4] 2> 2096813 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!60 (1437674751520669696)]} 0 0
[junit4:junit4] 2> 2096814 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[i!60 (1437674751520669696)]} 0 4
[junit4:junit4] 2> 2096815 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!60]} 0 8
[junit4:junit4] 2> 2096817 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!61 (1437674751528009728)]} 0 0
[junit4:junit4] 2> 2096822 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!61 (1437674751531155456)]} 0 0
[junit4:junit4] 2> 2096823 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!61 (1437674751531155456)]} 0 3
[junit4:junit4] 2> 2096827 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!62 (1437674751538495488)]} 0 0
[junit4:junit4] 2> 2096835 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!62 (1437674751544786944)]} 0 0
[junit4:junit4] 2> 2096836 T4462 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[k!62 (1437674751544786944)]} 0 3
[junit4:junit4] 2> 2096837 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!62]} 0 7
[junit4:junit4] 2> 2096840 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!63 (1437674751552126976)]} 0 0
[junit4:junit4] 2> 2096848 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!63 (1437674751558418432)]} 0 0
[junit4:junit4] 2> 2096849 T4476 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[l!63 (1437674751558418432)]} 0 3
[junit4:junit4] 2> 2096850 T4460 C2147 P29281 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!63]} 0 6
[junit4:junit4] 2> 2096852 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!64 (1437674751564709888)]} 0 0
[junit4:junit4] 2> 2096858 T4507 C2148 P29291 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29284/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!64 (1437674751568904192)]} 0 0
[junit4:junit4] 2> 2096859 T4478 C2149 P29284 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!64 (1437674751568904192)]} 0 3
[junit4:junit4] 2> 2096863 T4436 C2150 P29277 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!65 (1437674751576244224)]} 0 0
[junit4:junit4] 2> 2096870 T4488 C2146 P29287 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:29281/collection1/&upd
[...truncated too long message...]
lrCore org.apache.solr.core.SolrCore@10cdf32a
[junit4:junit4] 2> 2281315 T4515 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=580,adds=580,deletesById=286,deletesByQuery=0,errors=0,cumulative_adds=622,cumulative_deletesById=286,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4] 2> 2281315 T4515 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 2281316 T4515 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 2281316 T4515 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 2281324 T4515 C2165 P29291 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2742d9a2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@225bcc23),segFN=segments_4,generation=4}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2742d9a2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@225bcc23),segFN=segments_5,generation=5}
[junit4:junit4] 2> 2281324 T4515 C2165 P29291 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4:junit4] 2> 2281328 T4515 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 2281328 T4515 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 2281329 T4515 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4;done=false>>]
[junit4:junit4] 2> 2281329 T4515 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4
[junit4:junit4] 2> 2281329 T4515 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/index;done=false>>]
[junit4:junit4] 2> 2281330 T4515 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1371073452423/jetty4/index
[junit4:junit4] 2> 2281330 T4515 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2281330 T4515 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2281330 T4515 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2281331 T4515 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 2281331 T4515 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2281331 T4515 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {id=PostingsFormat(name=Lucene41WithOrds), _version_=MockFixedIntBlock(blockSize=812), n_ti=MockFixedIntBlock(blockSize=812)}, docValues:{}, sim=DefaultSimilarity, locale=th_TH_TH_#u-nu-thai, timezone=Europe/Gibraltar
[junit4:junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=2,free=90474232,total=536870912
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestFoldingMultitermQuery, FullSolrCloudDistribCmdsTest, TestOmitPositions, TestUniqueKeyFieldResource, IndexReaderFactoryTest, SuggesterWFSTTest, DisMaxRequestHandlerTest, TestLazyCores, TestZkChroot, TestRTGBase, TestDistributedGrouping, CurrencyFieldXmlFileTest, NumericFieldsTest, BadIndexSchemaTest, TestJmxMonitoredMap, LeaderElectionIntegrationTest, TestDistributedSearch, TestIndexingPerformance, TimeZoneUtilsTest, TestFiltering, SolrRequestParserTest, OutputWriterTest, TestCSVResponseWriter, ConvertedLegacyTest, IndexBasedSpellCheckerTest, OpenCloseCoreStressTest, TestJmxIntegration, TestMergePolicyConfig, RequiredFieldsTest, CollectionsAPIDistributedZkTest, TestSolrXml, TestManagedSchemaFieldResource, CopyFieldTest, SortByFunctionTest, TestFieldResource, SolrCoreCheckLockOnStartupTest, StatsComponentTest, TestCopyFieldCollectionResource, UniqFieldsUpdateProcessorFactoryTest, ChaosMonkeyShardSplitTest, TestSolrXMLSerializer, TestClassNameShortening, MultiTermTest, TestPropInject, SolrPluginUtilsTest, TestCollationField, JSONWriterTest, XsltUpdateRequestHandlerTest, FileUtilsTest, TestDFRSimilarityFactory, TestMultiCoreConfBootstrap, CoreContainerCoreInitFailuresTest, RequestHandlersTest, OpenExchangeRatesOrgProviderTest, HardAutoCommitTest, TestBinaryField, SolrCmdDistributorTest, SpellCheckComponentTest, TestDefaultSimilarityFactory, TestHashPartitioner, TestArbitraryIndexDir, ChaosMonkeySafeLeaderTest, TestFastOutputStream, DirectUpdateHandlerTest, TestFieldTypeResource, TestPartialUpdateDeduplication, TestRecovery, SuggesterTSTTest, TestElisionMultitermQuery, SampleTest, HighlighterTest, TestSolrQueryParserResource, BasicDistributedZk2Test, ShardRoutingTest, BasicZkTest, TestRandomFaceting, ShardRoutingCustomTest, AutoCommitTest, TestFaceting, DistributedSpellCheckComponentTest, TestStressReorder, TestReload, DistributedTermsComponentTest, TestRangeQuery, TestSolr4Spatial, SolrCoreTest, TestFunctionQuery, TestBadConfig, TestIndexSearcher, SoftAutoCommitTest, SolrIndexSplitterTest, SimplePostToolTest, SignatureUpdateProcessorFactoryTest, SpellCheckCollatorTest, CoreAdminHandlerTest, TestStressLucene, SpatialFilterTest, NoCacheHeaderTest, TestPseudoReturnFields, TestAtomicUpdateErrorCases, DefaultValueUpdateProcessorTest, DocValuesMultiTest, TestSolrDeletionPolicy1, DebugComponentTest, LukeRequestHandlerTest, DocumentAnalysisRequestHandlerTest, PrimitiveFieldTypeTest, XmlUpdateRequestHandlerTest, TestValueSourceCache, FieldAnalysisRequestHandlerTest, FastVectorHighlighterTest, RegexBoostProcessorTest, MBeansHandlerTest, TestAnalyzedSuggestions, PingRequestHandlerTest, TestBinaryResponseWriter, HighlighterConfigTest, TestPropInjectDefaults, AlternateDirectoryTest, TestQuerySenderNoQuery, SolrIndexConfigTest, TestSolrDeletionPolicy2, TestDocSet, TestSearchPerf, MinimalSchemaTest, TestFuzzyAnalyzedSuggestions, TestSolrCoreProperties, TestPostingsSolrHighlighter, NotRequiredUniqueKeyTest, TestLuceneMatchVersion, TestPhraseSuggestions, SpellPossibilityIteratorTest, TestCodecSupport, EchoParamsTest, TestPerFieldSimilarity, TestNumberUtils, TestLMJelinekMercerSimilarityFactory, TestBM25SimilarityFactory, LegacyHTMLStripCharFilterTest, TestPluginEnable, URLClassifyProcessorTest, TestFastLRUCache, DateMathParserTest, TestSystemIdResolver, PrimUtilsTest, TestSuggestSpellingConverter, SpellingQueryConverterTest, DOMUtilTest, ClusterStateTest, TestSolrJ, TestUtils, ZkNodePropsTest, UUIDFieldTest, CircularListTest, AliasIntegrationTest, ShardSplitTest]
[junit4:junit4] Completed on J1 in 218.32s, 1 test, 1 error <<< FAILURES!
[...truncated 10 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:385: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:365: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:437: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1240: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:884: There were test failures: 296 suites, 1243 tests, 1 error, 13 ignored (7 assumptions)
Total time: 58 minutes 9 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
Re: [JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4061 - Still Failing
Posted by Adrien Grand <jp...@gmail.com>.
I'll dig.
On Thu, Jun 13, 2013 at 6:30 AM, Apache Jenkins Server
<je...@builds.apache.org> wrote:
> Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4061/
>
> 1 tests failed.
> REGRESSION: org.apache.lucene.analysis.util.TestCharacterUtils.testConversions
>
> Error Message:
> expected:<-2> but was:<0>
>
> Stack Trace:
> java.lang.AssertionError: expected:<-2> but was:<0>
> at __randomizedtesting.SeedInfo.seed([48092F6AF46F2F70:4EB14D2C1D71191D]: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:472)
> at org.junit.Assert.assertEquals(Assert.java:456)
> at org.apache.lucene.analysis.util.TestCharacterUtils.testConversions(TestCharacterUtils.java:138)
> at org.apache.lucene.analysis.util.TestCharacterUtils.testConversions(TestCharacterUtils.java:126)
> 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:601)
> 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 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 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:722)
>
>
>
>
> Build Log:
> [...truncated 4722 lines...]
> [junit4:junit4] Suite: org.apache.lucene.analysis.util.TestCharacterUtils
> [junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestCharacterUtils -Dtests.method=testConversions -Dtests.seed=48092F6AF46F2F70 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=no -Dtests.timezone=Africa/Tripoli -Dtests.file.encoding=US-ASCII
> [junit4:junit4] FAILURE 0.09s J1 | TestCharacterUtils.testConversions <<<
> [junit4:junit4] > Throwable #1: java.lang.AssertionError: expected:<-2> but was:<0>
> [junit4:junit4] > at __randomizedtesting.SeedInfo.seed([48092F6AF46F2F70:4EB14D2C1D71191D]:0)
> [junit4:junit4] > at org.apache.lucene.analysis.util.TestCharacterUtils.testConversions(TestCharacterUtils.java:138)
> [junit4:junit4] > at org.apache.lucene.analysis.util.TestCharacterUtils.testConversions(TestCharacterUtils.java:126)
> [junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
> [junit4:junit4] 2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=no, timezone=Africa/Tripoli
> [junit4:junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=1,free=113693376,total=328204288
> [junit4:junit4] 2> NOTE: All tests run in this JVM: [TestHungarianLightStemFilterFactory, TestStopAnalyzer, TestHyphenatedWordsFilter, TestLimitTokenCountAnalyzer, TestEnglishMinimalStemFilterFactory, TestCzechAnalyzer, NumericPayloadTokenFilterTest, TestPersianNormalizationFilterFactory, TestTurkishAnalyzer, TestFinnishAnalyzer, TestMappingCharFilterFactory, TestPortugueseLightStemFilterFactory, TestKeywordMarkerFilter, TestKeywordMarkerFilterFactory, TestDelimitedPayloadTokenFilterFactory, TestArabicAnalyzer, TestASCIIFoldingFilter, TestRollingCharBuffer, TestWordlistLoader, TestCatalanAnalyzer, TestLimitTokenPositionFilter, TestCharArrayIterator, TestNGramFilters, TestHungarianLightStemFilter, TestGermanStemFilterFactory, TestPortugueseStemFilter, TestCapitalizationFilterFactory, TestPatternTokenizerFactory, TestIrishLowerCaseFilterFactory, TestRussianLightStemFilter, TestPorterStemFilter, TestSnowball, TestWikipediaTokenizerFactory, TestStandardAnalyzer, TestEmptyTokenStream, TestFrenchAnalyzer, TestSpanishLightStemFilter, TestStandardFactories, TestCommonGramsFilterFactory, HunspellDictionaryTest, TestElision, TestIrishAnalyzer, TestPorterStemFilterFactory, TestBulgarianStemmer, TestSwedishLightStemFilterFactory, TestLengthFilterFactory, TestPortugueseLightStemFilter, EdgeNGramTokenizerTest, TestCJKBigramFilterFactory, TestClassicAnalyzer, TestEnglishMinimalStemFilter, TestHTMLStripCharFilterFactory, TestCharacterUtils]
> [junit4:junit4] Completed on J1 in 0.13s, 9 tests, 1 failure <<< FAILURES!
>
> [...truncated 337 lines...]
> BUILD FAILED
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:385: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:365: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/build.xml:557: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1825: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/analysis/build.xml:105: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/analysis/build.xml:38: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/module-build.xml:61: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1240: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:884: There were test failures: 216 suites, 1205 tests, 1 failure, 1 ignored
>
> Total time: 10 minutes 29 seconds
> Build step 'Invoke Ant' marked build as failure
> Archiving artifacts
> Recording test results
> Email was triggered for: Failure
> Sending email for trigger: Failure
>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
--
Adrien
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4061 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4061/
1 tests failed.
REGRESSION: org.apache.lucene.analysis.util.TestCharacterUtils.testConversions
Error Message:
expected:<-2> but was:<0>
Stack Trace:
java.lang.AssertionError: expected:<-2> but was:<0>
at __randomizedtesting.SeedInfo.seed([48092F6AF46F2F70:4EB14D2C1D71191D]: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:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.lucene.analysis.util.TestCharacterUtils.testConversions(TestCharacterUtils.java:138)
at org.apache.lucene.analysis.util.TestCharacterUtils.testConversions(TestCharacterUtils.java:126)
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:601)
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 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 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:722)
Build Log:
[...truncated 4722 lines...]
[junit4:junit4] Suite: org.apache.lucene.analysis.util.TestCharacterUtils
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestCharacterUtils -Dtests.method=testConversions -Dtests.seed=48092F6AF46F2F70 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=no -Dtests.timezone=Africa/Tripoli -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE 0.09s J1 | TestCharacterUtils.testConversions <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: expected:<-2> but was:<0>
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([48092F6AF46F2F70:4EB14D2C1D71191D]:0)
[junit4:junit4] > at org.apache.lucene.analysis.util.TestCharacterUtils.testConversions(TestCharacterUtils.java:138)
[junit4:junit4] > at org.apache.lucene.analysis.util.TestCharacterUtils.testConversions(TestCharacterUtils.java:126)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=no, timezone=Africa/Tripoli
[junit4:junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=1,free=113693376,total=328204288
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestHungarianLightStemFilterFactory, TestStopAnalyzer, TestHyphenatedWordsFilter, TestLimitTokenCountAnalyzer, TestEnglishMinimalStemFilterFactory, TestCzechAnalyzer, NumericPayloadTokenFilterTest, TestPersianNormalizationFilterFactory, TestTurkishAnalyzer, TestFinnishAnalyzer, TestMappingCharFilterFactory, TestPortugueseLightStemFilterFactory, TestKeywordMarkerFilter, TestKeywordMarkerFilterFactory, TestDelimitedPayloadTokenFilterFactory, TestArabicAnalyzer, TestASCIIFoldingFilter, TestRollingCharBuffer, TestWordlistLoader, TestCatalanAnalyzer, TestLimitTokenPositionFilter, TestCharArrayIterator, TestNGramFilters, TestHungarianLightStemFilter, TestGermanStemFilterFactory, TestPortugueseStemFilter, TestCapitalizationFilterFactory, TestPatternTokenizerFactory, TestIrishLowerCaseFilterFactory, TestRussianLightStemFilter, TestPorterStemFilter, TestSnowball, TestWikipediaTokenizerFactory, TestStandardAnalyzer, TestEmptyTokenStream, TestFrenchAnalyzer, TestSpanishLightStemFilter, TestStandardFactories, TestCommonGramsFilterFactory, HunspellDictionaryTest, TestElision, TestIrishAnalyzer, TestPorterStemFilterFactory, TestBulgarianStemmer, TestSwedishLightStemFilterFactory, TestLengthFilterFactory, TestPortugueseLightStemFilter, EdgeNGramTokenizerTest, TestCJKBigramFilterFactory, TestClassicAnalyzer, TestEnglishMinimalStemFilter, TestHTMLStripCharFilterFactory, TestCharacterUtils]
[junit4:junit4] Completed on J1 in 0.13s, 9 tests, 1 failure <<< FAILURES!
[...truncated 337 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:385: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:365: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/build.xml:557: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1825: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/analysis/build.xml:105: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/analysis/build.xml:38: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/module-build.xml:61: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1240: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:884: There were test failures: 216 suites, 1205 tests, 1 failure, 1 ignored
Total time: 10 minutes 29 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure