You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/06/20 13:49:32 UTC
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0_20-ea-b15) -
Build # 10609 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10609/
Java: 64bit/jdk1.8.0_20-ea-b15 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
No live SolrServers available to handle this request
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
at __randomizedtesting.SeedInfo.seed([F5F09138B160AB56:74161F20C63FCB6A]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:317)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:659)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1141)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1110)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:236)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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.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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:360)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11415 lines...]
[junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/init-core-data-001
[junit4] 2> 1121347 T4714 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 1121347 T4714 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 1121349 T4714 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 1121350 T4714 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1121350 T4715 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1121450 T4714 oasc.ZkTestServer.run start zk server on port:56838
[junit4] 2> 1121451 T4714 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1121455 T4721 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67670cb5 name:ZooKeeperConnection Watcher:127.0.0.1:56838 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1121455 T4714 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1121456 T4714 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1121458 T4714 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1121459 T4716 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x146b90f55d50000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1121461 T4723 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@380bc526 name:ZooKeeperConnection Watcher:127.0.0.1:56838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1121461 T4714 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1121461 T4714 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1121467 T4714 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1121468 T4714 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1121469 T4714 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1121471 T4714 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1121472 T4714 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1121475 T4714 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1121475 T4714 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1121478 T4714 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1121479 T4714 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1121481 T4714 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1121481 T4714 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1121483 T4714 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1121484 T4714 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1121485 T4714 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1121486 T4714 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1121488 T4714 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1121488 T4714 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1121490 T4714 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1121490 T4714 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1121492 T4714 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1121493 T4714 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1121494 T4714 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1121495 T4714 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1121496 T4714 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1121497 T4714 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1121500 T4714 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1121503 T4725 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25ac7027 name:ZooKeeperConnection Watcher:127.0.0.1:56838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1121504 T4714 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1121725 T4714 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1121727 T4714 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 1121729 T4714 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:59518
[junit4] 2> 1121731 T4714 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1121731 T4714 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1121731 T4714 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-002
[junit4] 2> 1121732 T4714 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-002/'
[junit4] 2> 1121746 T4714 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-002/solr.xml
[junit4] 2> 1121756 T4714 oasc.CoreContainer.<init> New CoreContainer 837662513
[junit4] 2> 1121756 T4714 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-002/]
[junit4] 2> 1121757 T4714 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1121757 T4714 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1121758 T4714 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1121758 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1121758 T4714 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1121759 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1121759 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1121759 T4714 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1121760 T4714 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1121762 T4714 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1121762 T4714 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1121763 T4714 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1121763 T4714 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56838/solr
[junit4] 2> 1121764 T4714 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1121765 T4714 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1121767 T4736 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49afc1da name:ZooKeeperConnection Watcher:127.0.0.1:56838 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1121767 T4714 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1121768 T4716 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x146b90f55d50003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1121768 T4714 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1121769 T4738 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78ba4066 name:ZooKeeperConnection Watcher:127.0.0.1:56838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1121769 T4714 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1121770 T4714 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1121772 T4714 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1121774 T4714 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1121776 T4714 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1121777 T4714 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1121779 T4714 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1121783 T4714 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59518_
[junit4] 2> 1121784 T4714 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59518_
[junit4] 2> 1121785 T4714 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1121786 T4714 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1121788 T4714 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59518_
[junit4] 2> 1121788 T4714 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1121789 T4714 oasc.Overseer.start Overseer (id=91964317923344388-127.0.0.1:59518_-n_0000000000) starting
[junit4] 2> 1121791 T4714 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1121799 T4740 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1121799 T4714 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1121802 T4714 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1121804 T4714 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1121805 T4739 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1121807 T4741 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 1121808 T4741 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1121808 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1121808 T4741 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1121810 T4739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1121811 T4739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:59518",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59518_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1121811 T4739 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1121812 T4739 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1121814 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1121815 T4738 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1122809 T4741 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1122809 T4741 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1122810 T4741 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1122811 T4741 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1122812 T4741 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1122812 T4741 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-002/collection1/'
[junit4] 2> 1122813 T4741 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 1122814 T4741 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 1122814 T4741 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 1122840 T4741 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 1122848 T4741 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1122849 T4741 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1122855 T4741 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1122938 T4741 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1122941 T4741 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1122942 T4741 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1122948 T4741 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1122950 T4741 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1122953 T4741 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1122954 T4741 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1122954 T4741 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1122954 T4741 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1122955 T4741 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1122955 T4741 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1122955 T4741 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 1122955 T4741 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1122956 T4741 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/control/data/
[junit4] 2> 1122956 T4741 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@65b71835
[junit4] 2> 1122956 T4741 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/control/data
[junit4] 2> 1122957 T4741 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/control/data/index/
[junit4] 2> 1122957 T4741 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1122957 T4741 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/control/data/index
[junit4] 2> 1122957 T4741 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=13.1640625, floorSegmentMB=1.3515625, forceMergeDeletesPctAllowed=10.738558480769896, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8845305371688512
[junit4] 2> 1122958 T4741 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@30bedf2b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d13339c),segFN=segments_1,generation=1}
[junit4] 2> 1122958 T4741 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1122960 T4741 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1122961 T4741 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1122961 T4741 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1122961 T4741 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1122961 T4741 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1122961 T4741 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1122962 T4741 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1122962 T4741 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1122962 T4741 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1122962 T4741 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1122962 T4741 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1122963 T4741 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1122963 T4741 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1122963 T4741 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1122963 T4741 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1122963 T4741 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1122964 T4741 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 1122965 T4741 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1122967 T4741 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1122967 T4741 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1122968 T4741 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=87.2578125, floorSegmentMB=0.3583984375, forceMergeDeletesPctAllowed=18.467475263354846, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1122969 T4741 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@30bedf2b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d13339c),segFN=segments_1,generation=1}
[junit4] 2> 1122969 T4741 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1122969 T4741 oass.SolrIndexSearcher.<init> Opening Searcher@66d3afbc[collection1] main
[junit4] 2> 1122969 T4741 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1122970 T4741 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1122970 T4741 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1122971 T4741 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1122971 T4741 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1122971 T4741 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1122972 T4741 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1122973 T4741 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1122973 T4741 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1122973 T4741 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1122975 T4742 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@66d3afbc[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 1122977 T4741 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1122977 T4745 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:59518 collection:control_collection shard:shard1
[junit4] 2> 1122978 T4714 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 1122978 T4714 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1122981 T4745 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1122981 T4714 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1122986 T4747 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bb388cf name:ZooKeeperConnection Watcher:127.0.0.1:56838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1122987 T4714 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1122988 T4714 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1122989 T4714 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1122991 T4745 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1122992 T4745 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1122993 T4745 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C717 name=collection1 org.apache.solr.core.SolrCore@5931a98f url=https://127.0.0.1:59518/collection1 node=127.0.0.1:59518_ C717_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:59518, core=collection1, node_name=127.0.0.1:59518_}
[junit4] 2> 1122993 T4745 C717 P59518 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:59518/collection1/
[junit4] 2> 1122993 T4745 C717 P59518 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1122993 T4745 C717 P59518 oasc.SyncStrategy.syncToMe https://127.0.0.1:59518/collection1/ has no replicas
[junit4] 2> 1122994 T4745 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:59518/collection1/ shard1
[junit4] 2> 1122994 T4745 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1122994 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1122995 T4739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1123000 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1123001 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1123003 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1123104 T4747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1123104 T4738 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1123152 T4745 oasc.ZkController.register We are https://127.0.0.1:59518/collection1/ and leader is https://127.0.0.1:59518/collection1/
[junit4] 2> 1123152 T4745 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:59518
[junit4] 2> 1123152 T4745 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1123152 T4745 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 1123153 T4745 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1123154 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1123154 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1123154 T4745 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1123154 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1123155 T4739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1123156 T4739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"https://127.0.0.1:59518",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59518_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1123157 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1123227 T4714 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 1123227 T4714 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1123229 T4714 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 1123230 T4714 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:52120
[junit4] 2> 1123232 T4714 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1123233 T4714 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1123234 T4714 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-003
[junit4] 2> 1123234 T4714 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-003/'
[junit4] 2> 1123257 T4714 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-003/solr.xml
[junit4] 2> 1123258 T4747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1123258 T4738 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1123264 T4714 oasc.CoreContainer.<init> New CoreContainer 1017265348
[junit4] 2> 1123264 T4714 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-003/]
[junit4] 2> 1123265 T4714 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1123265 T4714 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1123266 T4714 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1123266 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1123266 T4714 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1123266 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1123266 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1123267 T4714 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1123267 T4714 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1123269 T4714 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1123269 T4714 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1123269 T4714 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1123270 T4714 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56838/solr
[junit4] 2> 1123270 T4714 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1123271 T4714 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1123272 T4758 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3bfefa22 name:ZooKeeperConnection Watcher:127.0.0.1:56838 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1123273 T4714 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1123275 T4714 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1123277 T4760 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c81659c name:ZooKeeperConnection Watcher:127.0.0.1:56838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1123278 T4714 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1123286 T4714 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1124288 T4714 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52120_
[junit4] 2> 1124289 T4714 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52120_
[junit4] 2> 1124294 T4761 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 1124294 T4761 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1124295 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1124295 T4761 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1124295 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1124296 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1124296 T4739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1124296 T4739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:52120",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52120_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1124297 T4739 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1124297 T4739 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1124299 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1124400 T4738 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1124401 T4760 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1124400 T4747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1125296 T4761 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1125296 T4761 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1125297 T4761 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1125297 T4761 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1125299 T4761 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1125299 T4761 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-003/collection1/'
[junit4] 2> 1125300 T4761 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 1125301 T4761 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 1125301 T4761 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 1125334 T4761 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 1125344 T4761 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1125346 T4761 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1125351 T4761 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1125424 T4761 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1125427 T4761 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1125428 T4761 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1125435 T4761 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1125437 T4761 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1125439 T4761 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1125440 T4761 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1125440 T4761 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1125441 T4761 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1125441 T4761 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1125441 T4761 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1125441 T4761 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1125442 T4761 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1125442 T4761 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-003/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/jetty1/
[junit4] 2> 1125442 T4761 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@65b71835
[junit4] 2> 1125443 T4761 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/jetty1
[junit4] 2> 1125443 T4761 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/jetty1/index/
[junit4] 2> 1125443 T4761 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1125444 T4761 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/jetty1/index
[junit4] 2> 1125444 T4761 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=13.1640625, floorSegmentMB=1.3515625, forceMergeDeletesPctAllowed=10.738558480769896, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8845305371688512
[junit4] 2> 1125444 T4761 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1640f6cf lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b06b480),segFN=segments_1,generation=1}
[junit4] 2> 1125444 T4761 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1125447 T4761 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1125447 T4761 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1125448 T4761 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1125448 T4761 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1125448 T4761 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1125448 T4761 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1125449 T4761 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1125449 T4761 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1125449 T4761 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1125450 T4761 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1125450 T4761 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1125450 T4761 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1125451 T4761 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1125451 T4761 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1125451 T4761 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1125452 T4761 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1125452 T4761 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 1125454 T4761 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1125456 T4761 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1125456 T4761 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1125456 T4761 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=87.2578125, floorSegmentMB=0.3583984375, forceMergeDeletesPctAllowed=18.467475263354846, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1125457 T4761 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1640f6cf lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b06b480),segFN=segments_1,generation=1}
[junit4] 2> 1125457 T4761 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1125457 T4761 oass.SolrIndexSearcher.<init> Opening Searcher@1bc59e65[collection1] main
[junit4] 2> 1125457 T4761 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1125458 T4761 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1125458 T4761 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1125459 T4761 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1125459 T4761 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1125459 T4761 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1125459 T4761 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1125459 T4761 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1125460 T4761 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1125460 T4761 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1125462 T4762 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1bc59e65[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 1125464 T4761 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1125465 T4765 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:52120 collection:collection1 shard:shard1
[junit4] 2> 1125465 T4714 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 1125465 T4714 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1125468 T4765 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1125473 T4765 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1125474 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1125474 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1125475 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1125475 T4765 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1125475 T4765 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1125475 T4739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C718 name=collection1 org.apache.solr.core.SolrCore@392473ba url=https://127.0.0.1:52120/collection1 node=127.0.0.1:52120_ C718_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:52120, core=collection1, node_name=127.0.0.1:52120_}
[junit4] 2> 1125475 T4765 C718 P52120 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:52120/collection1/
[junit4] 2> 1125476 T4765 C718 P52120 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1125476 T4765 C718 P52120 oasc.SyncStrategy.syncToMe https://127.0.0.1:52120/collection1/ has no replicas
[junit4] 2> 1125476 T4765 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:52120/collection1/ shard1
[junit4] 2> 1125476 T4765 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1125479 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1125481 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1125487 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1125588 T4747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1125588 T4738 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1125588 T4760 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1125632 T4765 oasc.ZkController.register We are https://127.0.0.1:52120/collection1/ and leader is https://127.0.0.1:52120/collection1/
[junit4] 2> 1125632 T4765 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:52120
[junit4] 2> 1125632 T4765 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1125633 T4765 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 1125633 T4765 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1125634 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1125634 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1125634 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1125634 T4765 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1125643 T4739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1125644 T4739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"https://127.0.0.1:52120",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52120_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1125645 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1125701 T4714 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 1125702 T4714 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1125704 T4714 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 1125705 T4714 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:42008
[junit4] 2> 1125707 T4714 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1125707 T4714 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1125707 T4714 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-004
[junit4] 2> 1125707 T4714 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-004/'
[junit4] 2> 1125719 T4714 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-004/solr.xml
[junit4] 2> 1125728 T4714 oasc.CoreContainer.<init> New CoreContainer 1726903729
[junit4] 2> 1125728 T4714 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-004/]
[junit4] 2> 1125729 T4714 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1125729 T4714 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1125730 T4714 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1125730 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1125730 T4714 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1125731 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1125731 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1125731 T4714 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1125732 T4714 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1125734 T4714 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1125734 T4714 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1125735 T4714 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1125735 T4714 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56838/solr
[junit4] 2> 1125736 T4714 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1125736 T4714 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1125738 T4776 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@22f4c2eb name:ZooKeeperConnection Watcher:127.0.0.1:56838 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1125738 T4714 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1125739 T4714 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1125740 T4778 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25beedcc name:ZooKeeperConnection Watcher:127.0.0.1:56838/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1125740 T4714 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1125745 T4714 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1125747 T4738 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1125747 T4760 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1125747 T4778 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1125747 T4747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1126749 T4714 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42008_
[junit4] 2> 1126751 T4714 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42008_
[junit4] 2> 1126760 T4779 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 1126760 T4779 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1126761 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1126761 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1126761 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1126761 T4779 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1126762 T4739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1126762 T4739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:42008",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:42008_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1126762 T4739 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1126762 T4739 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1126764 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1126866 T4738 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1126867 T4778 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1126866 T4760 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1126866 T4747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1127761 T4779 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1127762 T4779 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1127763 T4779 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1127763 T4779 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1127765 T4779 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1127765 T4779 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-004/collection1/'
[junit4] 2> 1127766 T4779 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 1127766 T4779 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 1127767 T4779 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 1127787 T4779 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 1127795 T4779 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1127796 T4779 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1127800 T4779 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1127876 T4779 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1127879 T4779 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1127880 T4779 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1127886 T4779 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1127888 T4779 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1127890 T4779 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1127891 T4779 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1127891 T4779 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1127891 T4779 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1127892 T4779 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1127892 T4779 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1127893 T4779 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1127893 T4779 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1127893 T4779 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-004/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/jetty2/
[junit4] 2> 1127893 T4779 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@65b71835
[junit4] 2> 1127894 T4779 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/jetty2
[junit4] 2> 1127894 T4779 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/jetty2/index/
[junit4] 2> 1127894 T4779 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1127895 T4779 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-001/jetty2/index
[junit4] 2> 1127895 T4779 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=13.1640625, floorSegmentMB=1.3515625, forceMergeDeletesPctAllowed=10.738558480769896, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8845305371688512
[junit4] 2> 1127895 T4779 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@5a13a4ca lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@219864fe),segFN=segments_1,generation=1}
[junit4] 2> 1127896 T4779 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1127898 T4779 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1127898 T4779 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1127898 T4779 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1127898 T4779 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1127899 T4779 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1127899 T4779 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1127899 T4779 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1127899 T4779 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1127899 T4779 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1127900 T4779 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1127900 T4779 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1127900 T4779 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1127900 T4779 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1127901 T4779 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1127901 T4779 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1127901 T4779 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1127901 T4779 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 1127903 T4779 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1127904 T4779 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1127904 T4779 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1127905 T4779 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=87.2578125, floorSegmentMB=0.3583984375, forceMergeDeletesPctAllowed=18.467475263354846, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1127905 T4779 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@5a13a4ca lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@219864fe),segFN=segments_1,generation=1}
[junit4] 2> 1127905 T4779 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1127905 T4779 oass.SolrIndexSearcher.<init> Opening Searcher@3791b4a3[collection1] main
[junit4] 2> 1127906 T4779 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1127906 T4779 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1127906 T4779 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1127907 T4779 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1127907 T4779 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1127907 T4779 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1127907 T4779 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1127907 T4779 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1127908 T4779 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1127908 T4779 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1127910 T4780 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3791b4a3[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 1127912 T4779 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1127912 T4783 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:42008 collection:collection1 shard:shard1
[junit4] 2> 1127912 T4714 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 1127913 T4714 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1127916 T4783 oasc.ZkController.register We are https://127.0.0.1:42008/collection1/ and leader is https://127.0.0.1:52120/collection1/
[junit4] 2> 1127916 T4783 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:42008
[junit4] 2> 1127916 T4783 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 1127916 T4783 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> 1127917 T4783 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C719 name=collection1 org.apache.solr.core.SolrCore@35648112 url=https://127.0.0.1:42008/collection1 node=127.0.0.1:42008_ C719_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:42008, core=collection1, node_name=127.0.0.1:42008_}
[junit4] 2> 1127917 T4784 C719 P42008 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 1127918 T4784 C719 P42008 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 1127918 T4784 C719 P42008 oasc.RecoveryStrategy.doRecovery Publishing state of core collection1 as recovering, leader is https://127.0.0.1:52120/collection1/ and I am https://127.0.0.1:42008/collection1/
[junit4] 2> 1127918 T4784 C719 P42008 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
[junit4] 2> 1127918 T4784 C719 P42008 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1127920 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1127920 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1127920 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1127921 T4739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1127921 T4739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "base_url":"https://127.0.0.1:42008",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:42008_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1127923 T4738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1127926 T4784 C719 P42008 oasc.RecoveryStrategy.sendPrepRecoveryCmd Sending prep recovery command to https://127.0.0.1:52120; WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1%3A42008_&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true
[junit4] 2> 1128004 T4753 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 1128005 T4753 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1128006 T4753 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 1128006 T4753 oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:42008_, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"down","base_url":"https://127.0.0.1:42008","core":"collection1","node_name":"127.0.0.1:42008_"}
[junit4] 2> 1128026 T4747 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1128026 T4738 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1128026 T4778 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1128026 T4760 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1128151 T4714 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 1128151 T4714 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1128154 T4714 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 1128155 T4714 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:34887
[junit4] 2> 1128156 T4714 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1128157 T4714 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1128157 T4714 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-005
[junit4] 2> 1128157 T4714 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-005/'
[junit4] 2> 1128167 T4714 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-005/solr.xml
[junit4] 2> 1128174 T4714 oasc.CoreContainer.<init> New CoreContainer 597529453
[junit4] 2> 1128174 T4714 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001/tempDir-005/]
[junit4] 2> 1128175 T4714 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1128175 T4714 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1128175 T4714 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1128175 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1128176 T4714 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1128176 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1128176 T4714 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1128176 T4714 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1128176 T4714 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1128178 T4714 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1128178 T4714 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1128179 T4714 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1128179 T4714 oasc.ZkContainer.initZooKeeper Zo
[...truncated too long message...]
ption.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:177)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:71)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:204)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:313)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:448)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:212)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:313)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:448)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:212)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:313)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:448)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:212)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:313)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:448)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:212)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:357)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1180164 T4818 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1180164 T4818 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1180164 T4818 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1180164 T4818 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:357)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5F09138B160AB56-001
[junit4] 2> NOTE: test params are: codec=DummyCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=DUMMY, chunkSize=19), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=DUMMY, chunkSize=19)), sim=DefaultSimilarity, locale=de_AT, timezone=Japan
[junit4] 2> NOTE: Linux 3.8.0-41-generic amd64/Oracle Corporation 1.8.0_20-ea (64-bit)/cpus=8,threads=1,free=167875632,total=398458880
[junit4] 2> NOTE: All tests run in this JVM: [AnalysisAfterCoreReloadTest, PeerSyncTest, MigrateRouteKeyTest, TestSearchPerf, TestAnalyzeInfixSuggestions, TestValueSourceCache, TestFieldTypeCollectionResource, CacheHeaderTest, ResponseLogComponentTest, SimpleFacetsTest, UnloadDistributedZkTest, HttpPartitionTest, SOLR749Test, TestPostingsSolrHighlighter, TestRealTimeGet, TestDistributedMissingSort, SliceStateTest, SuggesterFSTTest, TestCloudManagedSchema, SolrXmlInZkTest, LukeRequestHandlerTest, TestFieldCollectionResource, DistributedQueryComponentCustomSortTest, QueryElevationComponentTest, TestMiniSolrCloudCluster, SuggesterTest, RollingRestartTest, PreAnalyzedUpdateProcessorTest, IndexSchemaTest, CopyFieldTest, TestUtils, TestFieldSortValues, SliceStateUpdateTest, TestPerFieldSimilarity, HdfsCollectionsAPIDistributedZkTest, TestJoin, TestWriterPerf, HdfsDirectoryTest, ReturnFieldsTest, TestSchemaResource, AutoCommitTest, TestSolrQueryParserResource, TestSolrIndexConfig, DirectUpdateHandlerOptimizeTest, UpdateRequestProcessorFactoryTest, FieldFacetTest, TestInitQParser, AbstractAnalyticsFacetTest, TestStressVersions, TestDocSet, TestReplicationHandler, TestBlendedInfixSuggestions, TestFunctionQuery, StressHdfsTest, ScriptEngineTest, TestQueryUtils, InfoHandlerTest, CSVRequestHandlerTest, CoreAdminRequestStatusTest, EchoParamsTest, TestMaxScoreQueryParser, RankQueryTest, PrimitiveFieldTypeTest, SpellingQueryConverterTest, QueryParsingTest, DocValuesMissingTest, TestSurroundQueryParser, AnalysisErrorHandlingTest, TestShardHandlerFactory, ParsingFieldUpdateProcessorsTest, TestElisionMultitermQuery, TestCoreContainer, TestConfig, TestReversedWildcardFilterFactory, TestCursorMarkWithoutUniqueKey, MoreLikeThisHandlerTest, TestSchemaVersionResource, OverseerRolesTest, ShardSplitTest, TestChildDocTransformer, SolrCoreTest, HdfsBasicDistributedZk2Test, SearchHandlerTest, CoreAdminHandlerTest, TestDefaultSearchFieldResource, TestCopyFieldCollectionResource, ShowFileRequestHandlerTest, TestClassNameShortening, TestLFUCache, RegexBoostProcessorTest, TestSolrQueryParser, CoreAdminCreateDiscoverTest, BadComponentTest, DistributedTermsComponentTest, TestJmxMonitoredMap, SampleTest, TestManagedSynonymFilterFactory, LeaderElectionTest, ZkControllerTest, SyncSliceTest]
[junit4] Completed on J0 in 59.25s, 1 test, 1 error <<< FAILURES!
[...truncated 631 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1296: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:920: There were test failures: 415 suites, 1703 tests, 1 error, 36 ignored (15 assumptions)
Total time: 73 minutes 48 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0_20-ea-b15 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.7.0_60) - Build #
10610 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10610/
Java: 64bit/jdk1.7.0_60 -XX:+UseCompressedOops -XX:+UseParallelGC
2 tests failed.
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication
Error Message:
timed out waiting for collection1 startAt time to exceed: Fri Jun 20 08:18:24 MDT 2014
Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Fri Jun 20 08:18:24 MDT 2014
at __randomizedtesting.SeedInfo.seed([F5B60349D1D0C8C5:2C5ED1117386723]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1368)
at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication(TestReplicationHandler.java:1278)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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.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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:360)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
No live SolrServers available to handle this request
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
at __randomizedtesting.SeedInfo.seed([F5B60349D1D0C8C5:74508D51A68FA8F9]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:317)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:659)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1141)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1110)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:236)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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.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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:360)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11250 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/init-core-data-001
[junit4] 2> 821619 T3660 oas.SolrTestCaseJ4.setUp ###Starting doTestStressReplication
[junit4] 2> 821622 T3660 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 821648 T3660 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33539
[junit4] 2> 821649 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 821649 T3660 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 821649 T3660 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001
[junit4] 2> 821649 T3660 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/'
[junit4] 2> 821660 T3660 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/solr.xml
[junit4] 2> 821681 T3660 oasc.CoreContainer.<init> New CoreContainer 1869289637
[junit4] 2> 821681 T3660 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/]
[junit4] 2> 821682 T3660 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 821682 T3660 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 821682 T3660 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 821682 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 821683 T3660 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 821683 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 821683 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 821683 T3660 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 821683 T3660 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 821684 T3660 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 821684 T3660 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 821684 T3660 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 821687 T3670 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/'
[junit4] 2> 821719 T3670 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 821737 T3670 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 821738 T3670 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 821741 T3670 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 821746 T3670 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 821747 T3670 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/
[junit4] 2> 821747 T3670 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 821747 T3670 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data/
[junit4] 2> 821747 T3670 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 821748 T3670 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data
[junit4] 2> 821748 T3670 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data/index/
[junit4] 2> 821748 T3670 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 821749 T3670 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data/index
[junit4] 2> 821749 T3670 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=15.818359375, floorSegmentMB=0.9306640625, forceMergeDeletesPctAllowed=11.647530441979164, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8231018029516636
[junit4] 2> 821750 T3670 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1764f4a8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1eb98bd3),segFN=segments_1,generation=1}
[junit4] 2> 821750 T3670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 821751 T3670 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 821751 T3670 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 821751 T3670 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 821752 T3670 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 821752 T3670 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 821752 T3670 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 821752 T3670 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 821754 T3670 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 821755 T3670 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 821755 T3670 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 821756 T3670 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1308641959, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 821756 T3670 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1764f4a8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1eb98bd3),segFN=segments_1,generation=1}
[junit4] 2> 821756 T3670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 821757 T3670 oass.SolrIndexSearcher.<init> Opening Searcher@6da47fd0[collection1] main
[junit4] 2> 821757 T3670 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/conf
[junit4] 2> 821757 T3670 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/conf/}
[junit4] 2> 821757 T3670 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/conf
[junit4] 2> 821757 T3670 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 821758 T3670 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 821758 T3670 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 821758 T3670 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 821758 T3670 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 821758 T3670 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 821758 T3671 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6da47fd0[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 821759 T3660 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 821759 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 821762 T3660 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 821763 T3660 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49817
[junit4] 2> 821765 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 821765 T3660 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 821765 T3660 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002
[junit4] 2> 821765 T3660 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/'
[junit4] 2> 821786 T3660 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/solr.xml
[junit4] 2> 821815 T3660 oasc.CoreContainer.<init> New CoreContainer 433661554
[junit4] 2> 821815 T3660 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/]
[junit4] 2> 821816 T3660 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 821816 T3660 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 821817 T3660 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 821817 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 821817 T3660 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 821818 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 821818 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 821818 T3660 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 821818 T3660 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 821819 T3660 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 821819 T3660 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 821820 T3660 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 821823 T3682 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/'
[junit4] 2> 821847 T3682 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 821865 T3682 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 821865 T3682 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 821868 T3682 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 821874 T3682 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 821874 T3682 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/
[junit4] 2> 821875 T3682 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 821875 T3682 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/
[junit4] 2> 821875 T3682 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 821875 T3682 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data
[junit4] 2> 821876 T3682 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index/
[junit4] 2> 821876 T3682 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 821877 T3682 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index
[junit4] 2> 821877 T3682 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=15.818359375, floorSegmentMB=0.9306640625, forceMergeDeletesPctAllowed=11.647530441979164, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8231018029516636
[junit4] 2> 821878 T3682 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@57721831 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@35117ae2),segFN=segments_1,generation=1}
[junit4] 2> 821878 T3682 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 821879 T3682 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 821879 T3682 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 821879 T3682 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 821879 T3682 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 821879 T3682 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 821879 T3682 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 821880 T3682 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 821881 T3682 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 821882 T3682 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 821882 T3682 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 821883 T3682 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1308641959, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 821883 T3682 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@57721831 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@35117ae2),segFN=segments_1,generation=1}
[junit4] 2> 821884 T3682 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 821884 T3682 oass.SolrIndexSearcher.<init> Opening Searcher@4819feea[collection1] main
[junit4] 2> 821884 T3682 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/conf
[junit4] 2> 821884 T3682 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/conf/}
[junit4] 2> 821884 T3682 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/conf
[junit4] 2> 821885 T3682 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 821885 T3682 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 821885 T3682 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 821886 T3682 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 821887 T3682 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 821887 T3683 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4819feea[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 821887 T3660 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 821888 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 821910 T3660 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=433661554
[junit4] 2> 821912 T3660 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@7a7d10b
[junit4] 2> 821913 T3660 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 821913 T3660 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 821913 T3660 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 821913 T3660 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 821914 T3660 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 821914 T3660 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 821915 T3660 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data;done=false>>]
[junit4] 2> 821915 T3660 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data
[junit4] 2> 821915 T3660 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index;done=false>>]
[junit4] 2> 821915 T3660 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index
[junit4] 2> 821916 T3660 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 821969 T3660 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 821973 T3660 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52142
[junit4] 2> 821974 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 821975 T3660 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 821975 T3660 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002
[junit4] 2> 821976 T3660 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/'
[junit4] 2> 821992 T3660 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/solr.xml
[junit4] 2> 822016 T3660 oasc.CoreContainer.<init> New CoreContainer 1313939359
[junit4] 2> 822017 T3660 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/]
[junit4] 2> 822017 T3660 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 822017 T3660 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 822018 T3660 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 822018 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 822018 T3660 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 822018 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 822018 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 822019 T3660 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 822019 T3660 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 822019 T3660 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 822019 T3660 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 822020 T3660 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 822022 T3695 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/'
[junit4] 2> 822052 T3695 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 822075 T3695 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 822075 T3695 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 822078 T3695 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 822083 T3695 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 822084 T3695 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/
[junit4] 2> 822084 T3695 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 822084 T3695 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/
[junit4] 2> 822085 T3695 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 822085 T3695 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data
[junit4] 2> 822085 T3695 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index/
[junit4] 2> 822085 T3695 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 822086 T3695 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index
[junit4] 2> 822087 T3695 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=15.818359375, floorSegmentMB=0.9306640625, forceMergeDeletesPctAllowed=11.647530441979164, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8231018029516636
[junit4] 2> 822087 T3695 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@6a62d795 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6286a3f6),segFN=segments_1,generation=1}
[junit4] 2> 822087 T3695 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 822088 T3695 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 822088 T3695 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 822088 T3695 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 822089 T3695 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 822089 T3695 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 822089 T3695 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 822089 T3695 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 822090 T3695 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 822091 T3695 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 822091 T3695 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 822092 T3695 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1308641959, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 822092 T3695 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@6a62d795 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6286a3f6),segFN=segments_1,generation=1}
[junit4] 2> 822092 T3695 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 822093 T3695 oass.SolrIndexSearcher.<init> Opening Searcher@5baaa9f6[collection1] main
[junit4] 2> 822093 T3695 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/conf
[junit4] 2> 822093 T3695 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/conf/}
[junit4] 2> 822093 T3695 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/conf
[junit4] 2> 822093 T3695 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 822094 T3695 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 822094 T3695 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 822094 T3695 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 822094 T3695 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 822094 T3696 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5baaa9f6[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 822095 T3660 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 822095 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 822117 T3660 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1869289637
[junit4] 2> 822118 T3660 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@626f7816
[junit4] 2> 822118 T3660 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 822119 T3660 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 822119 T3660 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 822120 T3660 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 822121 T3660 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 822121 T3660 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 822121 T3660 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data/index;done=false>>]
[junit4] 2> 822122 T3660 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data/index
[junit4] 2> 822122 T3660 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data;done=false>>]
[junit4] 2> 822122 T3660 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data
[junit4] 2> 822123 T3660 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 822176 T3660 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 822178 T3660 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56923
[junit4] 2> 822179 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 822179 T3660 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 822179 T3660 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001
[junit4] 2> 822180 T3660 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/'
[junit4] 2> 822188 T3660 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/solr.xml
[junit4] 2> 822207 T3660 oasc.CoreContainer.<init> New CoreContainer 646831180
[junit4] 2> 822207 T3660 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/]
[junit4] 2> 822208 T3660 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 822208 T3660 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 822209 T3660 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 822209 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 822209 T3660 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 822209 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 822209 T3660 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 822210 T3660 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 822210 T3660 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 822210 T3660 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 822210 T3660 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 822211 T3660 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 822213 T3707 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/'
[junit4] 2> 822243 T3707 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 822261 T3707 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 822262 T3707 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 822265 T3707 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 822270 T3707 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 822271 T3707 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/
[junit4] 2> 822271 T3707 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 822271 T3707 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data/
[junit4] 2> 822271 T3707 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 822273 T3707 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data
[junit4] 2> 822273 T3707 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data/index/
[junit4] 2> 822273 T3707 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 822274 T3707 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/data/index
[junit4] 2> 822274 T3707 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=15.818359375, floorSegmentMB=0.9306640625, forceMergeDeletesPctAllowed=11.647530441979164, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8231018029516636
[junit4] 2> 822274 T3707 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@62ef80bb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@37f05b13),segFN=segments_1,generation=1}
[junit4] 2> 822275 T3707 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 822275 T3707 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 822276 T3707 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 822276 T3707 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 822276 T3707 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 822276 T3707 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 822276 T3707 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 822276 T3707 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 822277 T3707 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 822279 T3707 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 822279 T3707 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 822279 T3707 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1308641959, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 822280 T3707 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@62ef80bb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@37f05b13),segFN=segments_1,generation=1}
[junit4] 2> 822280 T3707 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 822280 T3707 oass.SolrIndexSearcher.<init> Opening Searcher@8a282c8[collection1] main
[junit4] 2> 822280 T3707 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/conf
[junit4] 2> 822280 T3707 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/conf/}
[junit4] 2> 822281 T3707 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-001/collection1/conf
[junit4] 2> 822281 T3707 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 822281 T3707 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 822281 T3707 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 822281 T3707 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml
[junit4] 2> 822282 T3707 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 822282 T3707 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 822282 T3708 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8a282c8[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 822282 T3660 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 822282 T3660 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> ASYNC NEW_CORE C489 name=collection1 org.apache.solr.core.SolrCore@724089ea
[junit4] 2> 822284 T3703 C489 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 822285 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:*} 0 1
[junit4] 2> ASYNC NEW_CORE C490 name=collection1 org.apache.solr.core.SolrCore@9a5776b
[junit4] 2> 822286 T3691 C490 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 822286 T3691 C490 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:*} 0 0
[junit4] 2> 822289 T3692 C490 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 822290 T3692 C490 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@6a62d795 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6286a3f6),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@6a62d795 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6286a3f6),segFN=segments_2,generation=2}
[junit4] 2> 822290 T3692 C490 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 822291 T3692 C490 oass.SolrIndexSearcher.<init> Opening Searcher@2af7e357[collection1] main
[junit4] 2> 822292 T3692 C490 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 822292 T3696 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2af7e357[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 822292 T3692 C490 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&waitSearcher=true&commit=true&version=2&wt=javabin} {commit=} 0 3
[junit4] 2> 822296 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[0]} 0 1
[junit4] 2> 822299 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[1]} 0 1
[junit4] 2> 822301 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[2]} 0 0
[junit4] 2> 822303 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[3]} 0 0
[junit4] 2> 822305 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[4]} 0 0
[junit4] 2> 822307 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[5]} 0 0
[junit4] 2> 822309 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[6]} 0 0
[junit4] 2> 822311 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[7]} 0 0
[junit4] 2> 822313 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[8]} 0 0
[junit4] 2> 822315 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[9]} 0 0
[junit4] 2> 822318 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[10]} 0 0
[junit4] 2> 822320 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[11]} 0 0
[junit4] 2> 822322 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[12]} 0 0
[junit4] 2> 822324 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[13]} 0 0
[junit4] 2> 822326 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[14]} 0 0
[junit4] 2> 822328 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[15]} 0 0
[junit4] 2> 822331 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[16]} 0 1
[junit4] 2> 822333 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[17]} 0 1
[junit4] 2> 822335 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[18]} 0 0
[junit4] 2> 822337 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[19]} 0 0
[junit4] 2> 822339 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[20]} 0 0
[junit4] 2> 822341 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[21]} 0 0
[junit4] 2> 822343 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[22]} 0 0
[junit4] 2> 822346 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[23]} 0 1
[junit4] 2> 822348 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[24]} 0 0
[junit4] 2> 822350 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[25]} 0 0
[junit4] 2> 822353 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[26]} 0 0
[junit4] 2> 822356 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[27]} 0 1
[junit4] 2> 822358 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[28]} 0 0
[junit4] 2> 822360 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[29]} 0 0
[junit4] 2> 822363 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[30]} 0 1
[junit4] 2> 822365 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[31]} 0 0
[junit4] 2> 822367 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[32]} 0 0
[junit4] 2> 822370 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[33]} 0 0
[junit4] 2> 822372 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[34]} 0 0
[junit4] 2> 822374 T3703 C489 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 822376 T3703 C489 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@62ef80bb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@37f05b13),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@62ef80bb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@37f05b13),segFN=segments_2,generation=2}
[junit4] 2> 822377 T3703 C489 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 822379 T3703 C489 oass.SolrIndexSearcher.<init> Opening Searcher@7d008ce4[collection1] main
[junit4] 2> 822379 T3703 C489 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 822379 T3708 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7d008ce4[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C35))}
[junit4] 2> 822379 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&waitSearcher=true&commit=true&version=2&wt=javabin} {commit=} 0 5
[junit4] 2> 822383 T3704 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&version=2&wt=javabin} hits=35 status=0 QTime=1
[junit4] 2> 822386 T3693 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&version=2&core=collection1&wt=javabin} status=0 QTime=1
[junit4] 2> 822388 T3710 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 822388 T3710 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 822389 T3705 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&version=2&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 822389 T3710 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4] 2> 822389 T3710 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
[junit4] 2> 822390 T3710 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 822393 T3706 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={generation=2&command=filelist&version=2&wt=javabin&qt=/replication} status=0 QTime=2
[junit4] 2> 822393 T3710 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
[junit4] 2> 822394 T3710 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index.20140620081804901
[junit4] 2> 822394 T3710 oash.SnapPuller.isIndexStale WARN File segments_2 expected to be 131 while it is 82
[junit4] 2> 822394 T3710 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(RAMDirectory@5785c0e1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@223597c4) fullCopy=true
[junit4] 2> 822396 T3703 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&generation=2&command=filecontent&wt=filestream&file=_0.tip&qt=/replication} status=0 QTime=0
[junit4] 2> 822399 T3704 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&generation=2&command=filecontent&wt=filestream&file=_0.doc&qt=/replication} status=0 QTime=0
[junit4] 2> 822401 T3705 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&generation=2&command=filecontent&wt=filestream&file=_0.tim&qt=/replication} status=0 QTime=0
[junit4] 2> 822404 T3706 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&generation=2&command=filecontent&wt=filestream&file=_0.nvm&qt=/replication} status=0 QTime=0
[junit4] 2> 822406 T3703 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&generation=2&command=filecontent&wt=filestream&file=_0.fdx&qt=/replication} status=0 QTime=0
[junit4] 2> 822409 T3704 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&generation=2&command=filecontent&wt=filestream&file=segments_2&qt=/replication} status=0 QTime=0
[junit4] 2> 822412 T3705 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&generation=2&command=filecontent&wt=filestream&file=_0.fdt&qt=/replication} status=0 QTime=0
[junit4] 2> 822414 T3706 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&generation=2&command=filecontent&wt=filestream&file=_0.nvd&qt=/replication} status=0 QTime=0
[junit4] 2> 822417 T3703 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&generation=2&command=filecontent&wt=filestream&file=_0.si&qt=/replication} status=0 QTime=0
[junit4] 2> 822419 T3704 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&generation=2&command=filecontent&wt=filestream&file=_0.fnm&qt=/replication} status=0 QTime=0
[junit4] 2> 822420 T3710 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 822420 T3710 oash.SnapPuller.downloadConfFiles Starting download of configuration files from master: [{checksum=1752577682, size=1656, name=schema.xml}]
[junit4] 2> 822425 T3705 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&generation=2&command=filecontent&cf=schema.xml&wt=filestream&qt=/replication} status=0 QTime=1
[junit4] 2> 822556 T3710 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20140620081804901
[junit4] 2> 822556 T3710 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirectoryWrapper(RAMDirectory@6a62d795 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6286a3f6)
[junit4] 2> 822556 T3710 oash.SnapPuller.fetchLatestIndex Configuration files are modified, core will be reloaded
[junit4] 2> 822558 T3712 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/'
[junit4] 2> 822598 T3712 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 822618 T3712 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 822618 T3712 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 822622 T3712 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 822628 T3712 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 822628 T3712 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using configuration from instancedir /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/
[junit4] 2> 822628 T3712 oasc.SolrCore.getNewIndexDir New index directory detected: old=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index/ new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index.20140620081804901
[junit4] 2> 822629 T3712 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/
[junit4] 2> 822629 T3712 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 822629 T3712 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index.20140620081804901
[junit4] 2> 822630 T3712 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 822630 T3712 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 822630 T3712 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 822630 T3712 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 822630 T3712 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 822631 T3712 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 822631 T3712 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 822633 T3712 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 822634 T3712 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 822634 T3712 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 822635 T3712 oass.SolrIndexSearcher.<init> Opening Searcher@673aa6b[collection1] main
[junit4] 2> 822635 T3712 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/conf
[junit4] 2> 822635 T3712 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/conf/}
[junit4] 2> 822635 T3712 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/conf
[junit4] 2> 822636 T3712 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 822636 T3712 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 822637 T3712 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 822637 T3712 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 822637 T3712 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 822637 T3712 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 822637 T3712 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4] 2> 822637 T3713 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@673aa6b[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 822638 T3712 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=25, maxMergedSegmentMB=50.25, floorSegmentMB=1.7373046875, forceMergeDeletesPctAllowed=0.6456244922128607, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 822639 T3712 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@5785c0e1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@223597c4),segFN=segments_2,generation=2}
[junit4] 2> 822639 T3712 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 822639 T3712 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 822640 T3712 oass.SolrIndexSearcher.<init> Opening Searcher@437a527d[collection1] main
[junit4] 2> 822640 T3712 oasc.CoreContainer.registerCore replacing core: collection1
[junit4] 2> 822640 T3713 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@437a527d[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C35))}
[junit4] 2> 822640 T3710 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirectoryWrapper(RAMDirectory@6a62d795 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6286a3f6)
[junit4] 2> 822642 T3710 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 822642 T3710 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 822642 T3710 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 822643 T3710 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=54.142578125, floorSegmentMB=2.15625, forceMergeDeletesPctAllowed=25.01223034777573, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4106008117861111
[junit4] 2> 822643 T3710 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@5785c0e1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@223597c4),segFN=segments_2,generation=2}
[junit4] 2> 822643 T3710 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 822644 T3710 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 822644 T3710 oass.SolrIndexSearcher.<init> Opening Searcher@7fd4ba9a[collection1] main
[junit4] 2> 822645 T3696 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7fd4ba9a[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C35))}
[junit4] 2> 822645 T3692 C490 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:56923/solr/replication&command=fetchindex&wait=true} status=0 QTime=258
[junit4] 2> 822646 T3692 C490 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index;done=true>>]
[junit4] 2> 822646 T3692 C490 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.handler.TestReplicationHandler-F5B60349D1D0C8C5-001/solr-instance-002/collection1/data/index
[junit4] 2> 822646 T3692 C490 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@9a5776b
[junit4] 2> 822647 T3692 C490 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4] 2> 822647 T3692 C490 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 822648 T3694 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&version=2&core=collection1&wt=javabin} status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C491 name=collection1 org.apache.solr.core.SolrCore@13bdaf27
[junit4] 2> 822651 T3693 C491 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&version=2&wt=javabin} hits=35 status=0 QTime=1
[junit4] 2> 822654 T3706 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&version=2&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 822657 T3704 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&version=2&wt=javabin&qt=/replication} status=0 QTime=1
[junit4] 2> 822659 T3691 C491 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&version=2&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 822662 T3705 C489 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=assertVersions&command=indexversion&version=2&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 822664 T3692 C491 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=assertVersions&command=indexversion&version=2&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 822670 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[35]} 0 2
[junit4] 2> 822673 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[36]} 0 1
[junit4] 2> 822675 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[37]} 0 0
[junit4] 2> 822678 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[38]} 0 0
[junit4] 2> 822681 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[39]} 0 0
[junit4] 2> 822684 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[40]} 0 1
[junit4] 2> 822686 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[41]} 0 0
[junit4] 2> 822689 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[42]} 0 1
[junit4] 2> 822692 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[43]} 0 1
[junit4] 2> 822694 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[44]} 0 0
[junit4] 2> 822697 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[45]} 0 0
[junit4] 2> 822699 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[46]} 0 0
[junit4] 2> 822702 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[47]} 0 0
[junit4] 2> 822705 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[48]} 0 0
[junit4] 2> 822707 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[49]} 0 0
[junit4] 2> 822710 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[50]} 0 1
[junit4] 2> 822713 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[51]} 0 1
[junit4] 2> 822715 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[52]} 0 0
[junit4] 2> 822718 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[53]} 0 0
[junit4] 2> 822725 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[54]} 0 0
[junit4] 2> 822728 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[55]} 0 0
[junit4] 2> 822731 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[56]} 0 0
[junit4] 2> 822734 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[57]} 0 0
[junit4] 2> 822736 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[58]} 0 0
[junit4] 2> 822739 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[59]} 0 1
[junit4] 2> 822741 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[60]} 0 0
[junit4] 2> 822743 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[61]} 0 0
[junit4] 2> 822746 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[62]} 0 1
[junit4] 2> 822748 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[63]} 0 0
[junit4] 2> 822750 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[64]} 0 0
[junit4] 2> 822753 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[65]} 0 0
[junit4] 2> 822755 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[66]} 0 0
[junit4] 2> 822758 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[67]} 0 1
[junit4] 2> 822760 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[68]} 0 0
[junit4] 2> 822762 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[69]} 0 0
[junit4] 2> 822764 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[70]} 0 0
[junit4] 2> 822767 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[71]} 0 1
[junit4] 2> 822769 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[72]} 0 0
[junit4] 2> 822771 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[73]} 0 0
[junit4] 2> 822774 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[74]} 0 1
[junit4] 2> 822776 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[75]} 0 0
[junit4] 2> 822778 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[76]} 0 0
[junit4] 2> 822781 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[77]} 0 1
[junit4] 2> 822783 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[78]} 0 0
[junit4] 2> 822785 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[79]} 0 0
[junit4] 2> 822787 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[80]} 0 0
[junit4] 2> 822790 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[81]} 0 1
[junit4] 2> 822792 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[82]} 0 0
[junit4] 2> 822794 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[83]} 0 0
[junit4] 2> 822797 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[84]} 0 0
[junit4] 2> 822799 T3704 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[85]} 0 0
[junit4] 2> 822802 T3705 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[86]} 0 1
[junit4] 2> 822804 T3703 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[87]} 0 0
[junit4] 2> 822806 T3706 C489 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[88]} 0 0
[junit4] 2> 822808 T3704 C489 oasup.LogU
[...truncated too long message...]
loud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:448)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:212)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:313)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:448)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:212)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:313)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:448)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:212)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:357)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1170680 T5059 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1170680 T5059 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1170680 T5059 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1170680 T5059 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:357)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=F5B60349D1D0C8C5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fr_CH -Dtests.timezone=Australia/West -Dtests.file.encoding=US-ASCII
[junit4] ERROR 63.0s J0 | SyncSliceTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
[junit4] > at __randomizedtesting.SeedInfo.seed([F5B60349D1D0C8C5:74508D51A68FA8F9]:0)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:317)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:659)
[junit4] > at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
[junit4] > at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1141)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1110)
[junit4] > at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:236)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1170683 T4957 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.SyncSliceTest-F5B60349D1D0C8C5-001
[junit4] 2> NOTE: test params are: codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=367), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=367)), sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=fr_CH, timezone=Australia/West
[junit4] 2> NOTE: Linux 3.8.0-41-generic amd64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=8,threads=1,free=76215112,total=357564416
[junit4] 2> NOTE: All tests run in this JVM: [TestAddFieldRealTimeGet, FileBasedSpellCheckerTest, TestDefaultSearchFieldResource, UpdateRequestProcessorFactoryTest, TestMiniSolrCloudCluster, HdfsBasicDistributedZk2Test, SolrIndexSplitterTest, TestTrie, TestSolrDeletionPolicy1, AnalysisErrorHandlingTest, SuggesterTest, DistribCursorPagingTest, CollectionsAPIAsyncDistributedZkTest, DistributedExpandComponentTest, DistributedSpellCheckComponentTest, LukeRequestHandlerTest, TestSearchPerf, UnloadDistributedZkTest, DocValuesMissingTest, SpatialFilterTest, TestCustomSort, TestFieldResource, TestConfig, SolrTestCaseJ4Test, MoreLikeThisHandlerTest, SampleTest, QueryResultKeyTest, SimpleFacetsTest, ConnectionManagerTest, OverseerTest, TestSort, ReturnFieldsTest, OverseerRolesTest, SliceStateUpdateTest, TestReversedWildcardFilterFactory, OverseerCollectionProcessorTest, TestWriterPerf, TestGroupingSearch, TestRecoveryHdfs, RangeFacetTest, TimeZoneUtilsTest, TestReloadAndDeleteDocs, WordBreakSolrSpellCheckerTest, TestSystemIdResolver, LoggingHandlerTest, TestSchemaResource, ClusterStateTest, TestFastLRUCache, TestBadConfig, TestSimpleQParserPlugin, TestSolrIndexConfig, CursorMarkTest, PrimitiveFieldTypeTest, SpellingQueryConverterTest, TestReplicationHandlerBackup, SearchHandlerTest, TestLuceneMatchVersion, TestMaxScoreQueryParser, JsonLoaderTest, MultiThreadedOCPTest, TestJmxMonitoredMap, TestQueryUtils, TestNonDefinedSimilarityFactory, PolyFieldTest, SynonymTokenizerTest, QueryParsingTest, EnumFieldTest, TestDistributedMissingSort, SchemaVersionSpecificBehaviorTest, PeerSyncTest, AnalyticsQueryTest, CoreAdminHandlerTest, TestUtils, RecoveryZkTest, ZkControllerTest, TestExpandComponent, TestStandardQParsers, TestFaceting, ShowFileRequestHandlerTest, TriLevelCompositeIdRoutingTest, TestFreeTextSuggestions, DistributedTermsComponentTest, TestCoreContainer, TestLFUCache, DocumentBuilderTest, TestCloudManagedSchema, SpellPossibilityIteratorTest, CoreAdminCreateDiscoverTest, UUIDFieldTest, TestReplicationHandler, TestExtendedDismaxParser, TestDocSet, TestCloudInspectUtil, IndexSchemaTest, AssignTest, TestExceedMaxTermLength, FieldMutatingUpdateProcessorTest, TestHighlightDedupGrouping, TestDefaultSimilarityFactory, BasicDistributedZkTest, BasicDistributedZk2Test, SyncSliceTest]
[junit4] Completed on J0 in 63.00s, 1 test, 1 error <<< FAILURES!
[...truncated 661 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1296: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:920: There were test failures: 415 suites, 1703 tests, 1 error, 1 failure, 36 ignored (15 assumptions)
Total time: 71 minutes 25 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_60 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any