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/05/02 21:54:39 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.8.0) - Build # 1512 -
Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1512/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
shard1 is not consistent. Got 118 from http://127.0.0.1:54028/collection1lastClient and got 119 from http://127.0.0.1:54065/collection1
Stack Trace:
java.lang.AssertionError: shard1 is not consistent. Got 118 from http://127.0.0.1:54028/collection1lastClient and got 119 from http://127.0.0.1:54065/collection1
at __randomizedtesting.SeedInfo.seed([CA5511A030B00E76:4BB39FB847EF6E4A]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1138)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1117)
at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:150)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java: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 10838 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/init-core-data-001
[junit4] 2> 630793 T2728 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 630793 T2728 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 630803 T2728 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 630805 T2728 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 630806 T2729 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 630907 T2728 oasc.ZkTestServer.run start zk server on port:54001
[junit4] 2> 630908 T2728 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 630918 T2735 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f936d53 name:ZooKeeperConnection Watcher:127.0.0.1:54001 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 630918 T2728 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 630919 T2728 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 630933 T2728 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 630940 T2737 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51c75cf1 name:ZooKeeperConnection Watcher:127.0.0.1:54001/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 630940 T2728 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 630940 T2728 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 630949 T2728 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 630956 T2728 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 630962 T2728 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 630970 T2728 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 630971 T2728 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 630983 T2728 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 630984 T2728 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 630997 T2728 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 630999 T2728 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 631008 T2728 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 631011 T2728 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 631020 T2728 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 631021 T2728 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 631033 T2728 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 631034 T2728 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 631043 T2728 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 631044 T2728 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 631053 T2728 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 631054 T2728 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 631062 T2728 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 631063 T2728 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 631070 T2728 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 631071 T2728 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 631079 T2728 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 631080 T2728 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 632612 T2728 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 632618 T2728 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54004
[junit4] 2> 632619 T2728 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 632619 T2728 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 632620 T2728 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-002
[junit4] 2> 632620 T2728 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-002/'
[junit4] 2> 632656 T2728 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-002/solr.xml
[junit4] 2> 632687 T2728 oasc.CoreContainer.<init> New CoreContainer 634318473
[junit4] 2> 632688 T2728 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-002/]
[junit4] 2> 632689 T2728 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 632689 T2728 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 632689 T2728 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 632690 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 632690 T2728 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 632690 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 632690 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 632691 T2728 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 632691 T2728 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 632692 T2728 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 632692 T2728 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 632692 T2728 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 632693 T2728 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54001/solr
[junit4] 2> 632693 T2728 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 632695 T2728 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 632700 T2748 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79c1e74b name:ZooKeeperConnection Watcher:127.0.0.1:54001 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 632701 T2728 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 632707 T2728 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 632710 T2750 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e9ddc1 name:ZooKeeperConnection Watcher:127.0.0.1:54001/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 632710 T2728 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 632713 T2728 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 632720 T2728 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 632728 T2728 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 632741 T2728 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 632757 T2728 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 632769 T2728 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 632774 T2728 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54004_
[junit4] 2> 632776 T2728 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54004_
[junit4] 2> 632783 T2728 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 632789 T2728 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 632800 T2728 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54004_
[junit4] 2> 632801 T2728 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 632807 T2728 oasc.Overseer.start Overseer (id=91688659033522179-127.0.0.1:54004_-n_0000000000) starting
[junit4] 2> 632816 T2728 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 632842 T2752 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 632844 T2728 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 632844 T2752 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:54004_
[junit4] 2> 632849 T2728 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 632853 T2728 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 632862 T2751 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 632867 T2753 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 632868 T2753 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 632869 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 632870 T2753 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 632872 T2751 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 632873 T2751 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:54004",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54004_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 632873 T2751 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 632873 T2751 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 632879 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 632879 T2750 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> 633871 T2753 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 633872 T2753 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 633874 T2753 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 633874 T2753 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 633877 T2753 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 633877 T2753 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-002/collection1/'
[junit4] 2> 633878 T2753 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 633878 T2753 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 633879 T2753 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 633925 T2753 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 633937 T2753 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 633941 T2753 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 633945 T2753 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 634080 T2753 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 634080 T2753 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 634082 T2753 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 634088 T2753 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 634146 T2753 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 634147 T2753 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 634147 T2753 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-002/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/control/data/
[junit4] 2> 634147 T2753 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@685cff4a
[junit4] 2> 634148 T2753 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/control/data
[junit4] 2> 634149 T2753 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/control/data/index/
[junit4] 2> 634150 T2753 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 634151 T2753 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/control/data/index
[junit4] 2> 634151 T2753 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=5.984375, floorSegmentMB=1.9326171875, forceMergeDeletesPctAllowed=0.44174644104255756, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 634156 T2753 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 634156 T2753 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 634159 T2753 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 634159 T2753 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 634159 T2753 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 634159 T2753 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 634160 T2753 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 634160 T2753 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 634160 T2753 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 634161 T2753 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 634161 T2753 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 634161 T2753 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 634162 T2753 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 634162 T2753 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 634162 T2753 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 634163 T2753 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 634163 T2753 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 634165 T2753 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 634171 T2753 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 634173 T2753 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 634174 T2753 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 634176 T2753 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=46, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.31617756376319006]
[junit4] 2> 634178 T2753 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 634178 T2753 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 634178 T2753 oass.SolrIndexSearcher.<init> Opening Searcher@379f526a[collection1] main
[junit4] 2> 634178 T2753 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 634181 T2753 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 634181 T2753 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 634183 T2753 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 634183 T2753 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 634183 T2753 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 634185 T2753 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 634185 T2753 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 634185 T2753 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 634185 T2753 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 634188 T2754 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@379f526a[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 634190 T2753 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 634191 T2757 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54004 collection:control_collection shard:shard1
[junit4] 2> 634192 T2728 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 634193 T2728 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 634194 T2757 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 634195 T2728 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 634200 T2759 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70417805 name:ZooKeeperConnection Watcher:127.0.0.1:54001/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 634200 T2728 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 634204 T2728 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 634210 T2728 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 634212 T2757 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 634220 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 634225 T2751 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 634228 T2757 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 634228 T2757 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C548 name=collection1 org.apache.solr.core.SolrCore@277f91e2 url=http://127.0.0.1:54004/collection1 node=127.0.0.1:54004_ C548_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:54004, core=collection1, node_name=127.0.0.1:54004_}
[junit4] 2> 634228 T2757 C548 P54004 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54004/collection1/
[junit4] 2> 634229 T2757 C548 P54004 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 634230 T2757 C548 P54004 oasc.SyncStrategy.syncToMe http://127.0.0.1:54004/collection1/ has no replicas
[junit4] 2> 634230 T2757 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54004/collection1/ shard1
[junit4] 2> 634230 T2757 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 634244 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 634253 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 634262 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 634371 T2750 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> 634373 T2759 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> 634410 T2757 oasc.ZkController.register We are http://127.0.0.1:54004/collection1/ and leader is http://127.0.0.1:54004/collection1/
[junit4] 2> 634410 T2757 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54004
[junit4] 2> 634410 T2757 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 634411 T2757 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 634411 T2757 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 634414 T2757 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 634414 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 634415 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 634415 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 634419 T2751 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 634423 T2751 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:54004",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54004_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 634436 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 634541 T2750 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> 634542 T2759 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> 635861 T2728 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 635862 T2728 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 635866 T2728 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54008
[junit4] 2> 635867 T2728 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 635868 T2728 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 635869 T2728 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-003
[junit4] 2> 635870 T2728 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-003/'
[junit4] 2> 635934 T2728 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-003/solr.xml
[junit4] 2> 635967 T2728 oasc.CoreContainer.<init> New CoreContainer 2014709207
[junit4] 2> 635967 T2728 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-003/]
[junit4] 2> 635968 T2728 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 635968 T2728 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 635968 T2728 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 635969 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 635969 T2728 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 635970 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 635970 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 635970 T2728 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 635971 T2728 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 635971 T2728 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 635971 T2728 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 635972 T2728 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 635972 T2728 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54001/solr
[junit4] 2> 635972 T2728 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 635974 T2728 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 635979 T2770 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@337b7079 name:ZooKeeperConnection Watcher:127.0.0.1:54001 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 635979 T2728 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 635985 T2728 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 635990 T2772 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@335b3592 name:ZooKeeperConnection Watcher:127.0.0.1:54001/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 635990 T2728 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 636011 T2728 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 637022 T2728 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54008_
[junit4] 2> 637030 T2728 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54008_
[junit4] 2> 637042 T2759 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 637043 T2750 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 637043 T2772 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 637057 T2773 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 637057 T2773 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 637059 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 637060 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 637060 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 637059 T2773 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 637064 T2751 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 637065 T2751 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:54008",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54008_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 637065 T2751 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 637065 T2751 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 637071 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 637072 T2759 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> 637073 T2750 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> 637073 T2772 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> 638062 T2773 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 638063 T2773 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 638066 T2773 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 638066 T2773 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 638072 T2773 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 638073 T2773 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-003/collection1/'
[junit4] 2> 638076 T2773 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 638077 T2773 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 638080 T2773 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 638149 T2773 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 638162 T2773 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 638166 T2773 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 638171 T2773 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 638293 T2773 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 638297 T2773 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 638298 T2773 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 638305 T2773 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 638367 T2773 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 638367 T2773 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 638367 T2773 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-003/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty1/
[junit4] 2> 638367 T2773 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@685cff4a
[junit4] 2> 638368 T2773 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty1
[junit4] 2> 638369 T2773 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty1/index/
[junit4] 2> 638370 T2773 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 638370 T2773 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty1/index
[junit4] 2> 638371 T2773 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=5.984375, floorSegmentMB=1.9326171875, forceMergeDeletesPctAllowed=0.44174644104255756, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 638374 T2773 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 638375 T2773 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 638378 T2773 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 638378 T2773 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 638379 T2773 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 638379 T2773 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 638380 T2773 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 638381 T2773 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 638381 T2773 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 638382 T2773 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 638382 T2773 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 638383 T2773 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 638384 T2773 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 638384 T2773 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 638385 T2773 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 638385 T2773 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 638385 T2773 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 638386 T2773 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 638395 T2773 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 638398 T2773 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 638398 T2773 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 638399 T2773 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=46, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.31617756376319006]
[junit4] 2> 638401 T2773 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 638401 T2773 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 638401 T2773 oass.SolrIndexSearcher.<init> Opening Searcher@2d35e88e[collection1] main
[junit4] 2> 638401 T2773 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 638404 T2773 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 638404 T2773 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 638406 T2773 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 638406 T2773 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 638406 T2773 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 638408 T2773 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 638408 T2773 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 638408 T2773 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 638408 T2773 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 638416 T2774 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2d35e88e[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 638416 T2773 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 638418 T2777 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54008 collection:collection1 shard:shard2
[junit4] 2> 638419 T2728 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 638419 T2728 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 638420 T2777 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 638436 T2777 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 638440 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 638442 T2777 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 638442 T2777 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C549 name=collection1 org.apache.solr.core.SolrCore@33868987 url=http://127.0.0.1:54008/collection1 node=127.0.0.1:54008_ C549_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:54008, core=collection1, node_name=127.0.0.1:54008_}
[junit4] 2> 638442 T2777 C549 P54008 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54008/collection1/
[junit4] 2> 638443 T2777 C549 P54008 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 638443 T2777 C549 P54008 oasc.SyncStrategy.syncToMe http://127.0.0.1:54008/collection1/ has no replicas
[junit4] 2> 638443 T2777 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54008/collection1/ shard2
[junit4] 2> 638444 T2777 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 638452 T2751 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 638461 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 638470 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 638576 T2750 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> 638578 T2759 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> 638578 T2772 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> 638615 T2777 oasc.ZkController.register We are http://127.0.0.1:54008/collection1/ and leader is http://127.0.0.1:54008/collection1/
[junit4] 2> 638616 T2777 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54008
[junit4] 2> 638616 T2777 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 638618 T2777 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 638618 T2777 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 638621 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 638621 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 638621 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 638627 T2751 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 638630 T2751 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:54008",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54008_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 638637 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 638637 T2777 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 638747 T2750 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> 638747 T2772 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> 638748 T2759 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> 640063 T2728 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 640064 T2728 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 640068 T2728 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54011
[junit4] 2> 640069 T2728 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 640069 T2728 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 640069 T2728 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-004
[junit4] 2> 640070 T2728 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-004/'
[junit4] 2> 640103 T2728 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-004/solr.xml
[junit4] 2> 640129 T2728 oasc.CoreContainer.<init> New CoreContainer 384415584
[junit4] 2> 640129 T2728 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-004/]
[junit4] 2> 640129 T2728 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 640130 T2728 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 640130 T2728 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 640131 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 640131 T2728 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 640132 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 640132 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 640132 T2728 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 640133 T2728 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 640133 T2728 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 640134 T2728 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 640134 T2728 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 640134 T2728 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54001/solr
[junit4] 2> 640135 T2728 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 640136 T2728 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 640146 T2788 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c136fdc name:ZooKeeperConnection Watcher:127.0.0.1:54001 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 640146 T2728 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 640152 T2728 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 640157 T2790 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@174b2fa2 name:ZooKeeperConnection Watcher:127.0.0.1:54001/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 640157 T2728 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 640177 T2728 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 641189 T2728 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54011_
[junit4] 2> 641194 T2728 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54011_
[junit4] 2> 641210 T2772 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 641211 T2790 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 641210 T2750 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 641214 T2759 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 641235 T2791 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 641235 T2791 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 641239 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 641240 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 641241 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 641240 T2791 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 641249 T2751 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 641251 T2751 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:54011",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54011_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 641252 T2751 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 641252 T2751 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 641266 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 641272 T2759 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> 641273 T2790 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> 641273 T2750 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> 641273 T2772 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> 642243 T2791 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 642244 T2791 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 642247 T2791 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 642248 T2791 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 642253 T2791 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 642253 T2791 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-004/collection1/'
[junit4] 2> 642256 T2791 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 642257 T2791 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 642258 T2791 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 642310 T2791 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 642321 T2791 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 642324 T2791 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 642329 T2791 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 642453 T2791 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 642455 T2791 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 642456 T2791 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 642461 T2791 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 642521 T2791 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 642521 T2791 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 642522 T2791 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-004/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty2/
[junit4] 2> 642522 T2791 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@685cff4a
[junit4] 2> 642523 T2791 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty2
[junit4] 2> 642523 T2791 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty2/index/
[junit4] 2> 642524 T2791 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 642525 T2791 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty2/index
[junit4] 2> 642527 T2791 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=5.984375, floorSegmentMB=1.9326171875, forceMergeDeletesPctAllowed=0.44174644104255756, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 642532 T2791 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 642532 T2791 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 642535 T2791 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 642535 T2791 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 642536 T2791 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 642537 T2791 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 642537 T2791 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 642537 T2791 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 642538 T2791 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 642538 T2791 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 642538 T2791 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 642539 T2791 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 642540 T2791 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 642540 T2791 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 642540 T2791 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 642541 T2791 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 642541 T2791 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 642542 T2791 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 642550 T2791 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 642552 T2791 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 642552 T2791 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 642553 T2791 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=46, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.31617756376319006]
[junit4] 2> 642554 T2791 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 642554 T2791 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 642555 T2791 oass.SolrIndexSearcher.<init> Opening Searcher@14071341[collection1] main
[junit4] 2> 642556 T2791 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 642559 T2791 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 642559 T2791 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 642560 T2791 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 642560 T2791 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 642561 T2791 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 642563 T2791 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 642563 T2791 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 642563 T2791 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 642564 T2791 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 642566 T2792 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14071341[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 642568 T2791 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 642570 T2795 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54011 collection:collection1 shard:shard3
[junit4] 2> 642571 T2728 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 642571 T2728 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 642572 T2795 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 642583 T2795 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
[junit4] 2> 642589 T2795 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 642589 T2795 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C550 name=collection1 org.apache.solr.core.SolrCore@3967d3d0 url=http://127.0.0.1:54011/collection1 node=127.0.0.1:54011_ C550_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:54011, core=collection1, node_name=127.0.0.1:54011_}
[junit4] 2> 642590 T2795 C550 P54011 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54011/collection1/
[junit4] 2> 642590 T2795 C550 P54011 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 642590 T2795 C550 P54011 oasc.SyncStrategy.syncToMe http://127.0.0.1:54011/collection1/ has no replicas
[junit4] 2> 642590 T2795 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54011/collection1/ shard3
[junit4] 2> 642591 T2795 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 642595 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 642600 T2751 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 642630 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 642643 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 642748 T2772 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> 642750 T2759 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> 642749 T2750 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> 642750 T2790 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> 642789 T2795 oasc.ZkController.register We are http://127.0.0.1:54011/collection1/ and leader is http://127.0.0.1:54011/collection1/
[junit4] 2> 642790 T2795 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54011
[junit4] 2> 642790 T2795 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 642790 T2795 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 642790 T2795 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 642793 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 642793 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 642793 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 642795 T2795 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 642797 T2751 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 642800 T2751 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:54011",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54011_",
[junit4] 2> "shard":"shard3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 642805 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 642911 T2772 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> 642911 T2759 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> 642911 T2750 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> 642911 T2790 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> 644294 T2728 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 644295 T2728 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 644307 T2728 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54014
[junit4] 2> 644308 T2728 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 644309 T2728 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 644310 T2728 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-005
[junit4] 2> 644310 T2728 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-005/'
[junit4] 2> 644362 T2728 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-005/solr.xml
[junit4] 2> 644394 T2728 oasc.CoreContainer.<init> New CoreContainer 895159671
[junit4] 2> 644395 T2728 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-005/]
[junit4] 2> 644396 T2728 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 644397 T2728 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 644397 T2728 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 644398 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 644399 T2728 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 644399 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 644400 T2728 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 644400 T2728 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 644405 T2728 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 644423 T2728 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 644425 T2728 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 644425 T2728 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 644425 T2728 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54001/solr
[junit4] 2> 644426 T2728 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 644430 T2728 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 644435 T2806 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@208a8db1 name:ZooKeeperConnection Watcher:127.0.0.1:54001 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 644436 T2728 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 644450 T2728 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 644453 T2808 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b86cdd7 name:ZooKeeperConnection Watcher:127.0.0.1:54001/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 644454 T2728 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 644485 T2728 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 645494 T2728 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54014_
[junit4] 2> 645497 T2728 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54014_
[junit4] 2> 645508 T2772 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 645509 T2790 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 645509 T2750 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 645510 T2759 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 645511 T2808 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 645527 T2809 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 645528 T2809 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 645530 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 645531 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 645531 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 645530 T2809 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 645536 T2751 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 645538 T2751 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:54014",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54014_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 645538 T2751 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 645538 T2751 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 645545 T2750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 645547 T2790 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> 645548 T2808 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> 645548 T2759 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> 645548 T2750 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> 645547 T2772 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> 646535 T2809 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 646535 T2809 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 646537 T2809 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 646537 T2809 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 646539 T2809 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 646540 T2809 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-005/collection1/'
[junit4] 2> 646542 T2809 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-005/collection1/lib/.svn/' to classloader
[junit4] 2> 646562 T2809 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-005/collection1/lib/classes/' to classloader
[junit4] 2> 646563 T2809 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B0
[...truncated too long message...]
/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty10;done=false>>]
[junit4] 2> 765700 T2951 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty10
[junit4] 2> 765700 T2951 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty10/index [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty10/index;done=false>>]
[junit4] 2> 765700 T2951 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty10/index
[junit4] 2> 765701 T2951 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> 765701 T2951 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 765701 T2951 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 765701 T2951 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 765701 T2951 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 765701 T2951 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 765702 T2951 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 765702 T2951 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 765702 T2951 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 765718 T3201 C877 P54059 oasc.SyncStrategy.sync WARN Closed, skipping sync up.
[junit4] 2> 765718 T3201 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4] 2> 765719 T3201 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@4fbdb333
[junit4] 2> 765721 T3201 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=23,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=65,cumulative_deletesById=31,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=23462,transaction_logs_total_number=5}
[junit4] 2> 765721 T3201 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 765722 T3201 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 765722 T3201 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 765724 T3201 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 765725 T3201 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 765725 T3201 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty11 [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty11;done=false>>]
[junit4] 2> 765726 T3201 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty11
[junit4] 2> 765726 T3201 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty11/index [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty11/index;done=false>>]
[junit4] 2> 765727 T3201 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001/tempDir-001/jetty11/index
[junit4] 2> 765727 T3201 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:303)
[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> 765727 T3201 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 765728 T3201 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> 765728 T3201 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.ChaosMonkeySafeLeaderTest-CA5511A030B00E76-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene46), sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=es_VE, timezone=Europe/Moscow
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_05 (64-bit)/cpus=2,threads=1,free=91707392,total=306184192
[junit4] 2> NOTE: All tests run in this JVM: [SuggesterTSTTest, DebugComponentTest, SyncSliceTest, CoreMergeIndexesAdminHandlerTest, TestReplicationHandler, SolrCmdDistributorTest, XsltUpdateRequestHandlerTest, CircularListTest, CoreAdminRequestStatusTest, ShardRoutingTest, TestDefaultSimilarityFactory, TestCodecSupport, TestCollationField, TestDynamicFieldResource, TestShardHandlerFactory, DirectUpdateHandlerOptimizeTest, DistributedTermsComponentTest, TestSolrQueryParserResource, AddSchemaFieldsUpdateProcessorFactoryTest, TestPHPSerializedResponseWriter, IndexBasedSpellCheckerTest, TestOverriddenPrefixQueryForCustomFieldType, CollectionsAPIDistributedZkTest, AsyncMigrateRouteKeyTest, TestStressVersions, TestPhraseSuggestions, TestSolrDeletionPolicy2, UUIDFieldTest, SimpleFacetsTest, TestRandomFaceting, OverseerRolesTest, TestFaceting, LegacyHTMLStripCharFilterTest, NotRequiredUniqueKeyTest, SolrTestCaseJ4Test, TestRTGBase, BasicZkTest, ChaosMonkeySafeLeaderTest]
[junit4] Completed in 135.06s, 1 test, 1 failure <<< FAILURES!
[...truncated 1089 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1297: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:921: There were test failures: 389 suites, 1626 tests, 1 failure, 42 ignored (15 assumptions)
Total time: 90 minutes 0 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 1513 -
Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1513/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
SPLITSHARD failed to create subshard leaders
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: SPLITSHARD failed to create subshard leaders
at __randomizedtesting.SeedInfo.seed([963C9151C73C5F1F:17DA1F49B0633F23]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:554)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
at org.apache.solr.client.solrj.request.CollectionAdminRequest.process(CollectionAdminRequest.java:300)
at org.apache.solr.client.solrj.request.CollectionAdminRequest.splitShard(CollectionAdminRequest.java:478)
at org.apache.solr.client.solrj.request.CollectionAdminRequest.splitShard(CollectionAdminRequest.java:483)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:313)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:203)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java: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 11006 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/init-core-data-001
[junit4] 2> 1610061 T4085 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 1610063 T4085 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 1610074 T4085 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 1610075 T4085 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1610078 T4086 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1610179 T4085 oasc.ZkTestServer.run start zk server on port:52757
[junit4] 2> 1610181 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1610189 T4092 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b956dab name:ZooKeeperConnection Watcher:127.0.0.1:52757 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1610190 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1610190 T4085 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1610204 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1610209 T4094 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7588d3f2 name:ZooKeeperConnection Watcher:127.0.0.1:52757/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1610209 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1610210 T4085 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1610221 T4085 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1610229 T4085 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1610237 T4085 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1610248 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1610249 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1610262 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1610263 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1610272 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1610273 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1610282 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1610283 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1610292 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1610293 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1610303 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1610305 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1610314 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1610315 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1610323 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1610324 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1610333 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1610333 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1610342 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1610343 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1610352 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1610353 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> Using old style solr.xml
[junit4] 2> 1610367 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1610371 T4096 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@625fb896 name:ZooKeeperConnection Watcher:127.0.0.1:52757 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1610372 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1610372 T4085 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1610383 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1610388 T4098 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f260f52 name:ZooKeeperConnection Watcher:127.0.0.1:52757/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1610388 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1610390 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
[junit4] 2> 1610390 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
[junit4] 2> 1610404 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
[junit4] 2> 1610405 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
[junit4] 2> 1610416 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1610416 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1610425 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
[junit4] 2> 1610426 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
[junit4] 2> 1610434 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
[junit4] 2> 1610435 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
[junit4] 2> 1610448 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
[junit4] 2> 1610450 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
[junit4] 2> 1610459 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
[junit4] 2> 1610461 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
[junit4] 2> 1610473 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 1610474 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 1610487 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
[junit4] 2> 1610488 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
[junit4] 2> 1610506 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
[junit4] 2> 1610507 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
[junit4] 2> 1610518 T4085 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
[junit4] 2> 1610519 T4085 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
[junit4] 2> 1612270 T4085 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1612274 T4085 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52762
[junit4] 2> 1612275 T4085 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1612276 T4085 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1612276 T4085 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-002
[junit4] 2> 1612276 T4085 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-002/'
[junit4] 2> 1612330 T4085 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-002/solr.xml
[junit4] 2> 1612445 T4085 oasc.CoreContainer.<init> New CoreContainer 121491726
[junit4] 2> 1612445 T4085 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-002/]
[junit4] 2> 1612447 T4085 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1612447 T4085 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 1612448 T4085 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1612449 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1612449 T4085 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1612450 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1612450 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1612450 T4085 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1612450 T4085 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1612451 T4085 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1612452 T4085 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1612452 T4085 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1612453 T4085 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52757/solr
[junit4] 2> 1612453 T4085 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1612455 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1612463 T4109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b67f1d8 name:ZooKeeperConnection Watcher:127.0.0.1:52757 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1612464 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1612471 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1612474 T4111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28cf6199 name:ZooKeeperConnection Watcher:127.0.0.1:52757/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1612475 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1612480 T4085 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1612492 T4085 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1612503 T4085 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1612516 T4085 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1612527 T4085 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1612538 T4085 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1612543 T4085 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52762_
[junit4] 2> 1612546 T4085 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52762_
[junit4] 2> 1612557 T4085 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1612564 T4085 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1612576 T4085 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52762_
[junit4] 2> 1612576 T4085 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1612583 T4085 oasc.Overseer.start Overseer (id=91690300834512901-127.0.0.1:52762_-n_0000000000) starting
[junit4] 2> 1612592 T4085 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1612625 T4113 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1612626 T4085 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1612629 T4113 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:52762_
[junit4] 2> 1612635 T4085 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1612641 T4085 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1612652 T4112 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1612658 T4085 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1612659 T4085 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1612661 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1612665 T4116 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32960baf name:ZooKeeperConnection Watcher:127.0.0.1:52757/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1612666 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1612670 T4085 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1612679 T4085 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1614581 T4085 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 1614582 T4085 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1614587 T4085 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52766
[junit4] 2> 1614589 T4085 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1614589 T4085 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1614589 T4085 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003
[junit4] 2> 1614589 T4085 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003/'
[junit4] 2> 1614635 T4085 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003/solr.xml
[junit4] 2> 1614757 T4085 oasc.CoreContainer.<init> New CoreContainer 926990118
[junit4] 2> 1614758 T4085 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003/]
[junit4] 2> 1614760 T4085 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1614760 T4085 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 1614760 T4085 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1614760 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1614761 T4085 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1614761 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1614761 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1614761 T4085 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1614762 T4085 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1614762 T4085 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1614763 T4085 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1614763 T4085 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1614764 T4085 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52757/solr
[junit4] 2> 1614764 T4085 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1614766 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1614771 T4127 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7bc57420 name:ZooKeeperConnection Watcher:127.0.0.1:52757 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1614772 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1614778 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1614781 T4129 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@86498bc name:ZooKeeperConnection Watcher:127.0.0.1:52757/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1614782 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1614803 T4085 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1615813 T4085 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52766_
[junit4] 2> 1615816 T4085 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52766_
[junit4] 2> 1615827 T4129 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1615827 T4111 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1615828 T4116 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1615849 T4085 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1615849 T4085 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1617655 T4085 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 1617656 T4085 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1617661 T4085 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52769
[junit4] 2> 1617663 T4085 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1617664 T4085 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1617664 T4085 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-004
[junit4] 2> 1617664 T4085 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-004/'
[junit4] 2> 1617702 T4085 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-004/solr.xml
[junit4] 2> 1617821 T4085 oasc.CoreContainer.<init> New CoreContainer 802031048
[junit4] 2> 1617822 T4085 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-004/]
[junit4] 2> 1617825 T4085 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1617826 T4085 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 1617826 T4085 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1617827 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1617828 T4085 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1617830 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1617830 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1617830 T4085 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1617831 T4085 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1617832 T4085 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1617833 T4085 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1617834 T4085 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1617834 T4085 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52757/solr
[junit4] 2> 1617835 T4085 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1617837 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1617841 T4141 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7edda5fc name:ZooKeeperConnection Watcher:127.0.0.1:52757 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1617842 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1617849 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1617853 T4143 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f477d5d name:ZooKeeperConnection Watcher:127.0.0.1:52757/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1617853 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1617872 T4085 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1618885 T4085 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52769_
[junit4] 2> 1618890 T4085 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52769_
[junit4] 2> 1618912 T4111 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1618913 T4143 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1618914 T4116 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1618914 T4129 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1618931 T4085 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1618931 T4085 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1620736 T4085 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 1620736 T4085 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1620745 T4085 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52772
[junit4] 2> 1620746 T4085 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1620747 T4085 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1620747 T4085 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005
[junit4] 2> 1620747 T4085 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005/'
[junit4] 2> 1620791 T4085 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005/solr.xml
[junit4] 2> 1620910 T4085 oasc.CoreContainer.<init> New CoreContainer 1400659906
[junit4] 2> 1620911 T4085 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005/]
[junit4] 2> 1620913 T4085 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1620913 T4085 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 1620914 T4085 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1620914 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1620914 T4085 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1620914 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1620915 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1620915 T4085 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1620915 T4085 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1620916 T4085 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1620917 T4085 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1620917 T4085 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1620917 T4085 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52757/solr
[junit4] 2> 1620918 T4085 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1620919 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1620924 T4155 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a72e460 name:ZooKeeperConnection Watcher:127.0.0.1:52757 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1620926 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1620934 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1620939 T4157 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70126ca0 name:ZooKeeperConnection Watcher:127.0.0.1:52757/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1620940 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1620967 T4085 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1621983 T4085 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52772_
[junit4] 2> 1621988 T4085 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52772_
[junit4] 2> 1622008 T4111 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1622010 T4116 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1622010 T4129 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1622012 T4157 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1622011 T4143 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1622052 T4085 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1622053 T4085 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1623869 T4085 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 4
[junit4] 2> 1623869 T4085 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1623878 T4085 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52775
[junit4] 2> 1623880 T4085 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1623881 T4085 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1623881 T4085 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006
[junit4] 2> 1623881 T4085 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006/'
[junit4] 2> 1623934 T4085 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006/solr.xml
[junit4] 2> 1624054 T4085 oasc.CoreContainer.<init> New CoreContainer 2015793698
[junit4] 2> 1624054 T4085 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006/]
[junit4] 2> 1624057 T4085 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1624058 T4085 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 1624058 T4085 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1624058 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1624059 T4085 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1624059 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1624060 T4085 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1624060 T4085 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1624060 T4085 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1624061 T4085 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1624062 T4085 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1624063 T4085 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1624064 T4085 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52757/solr
[junit4] 2> 1624066 T4085 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1624070 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1624077 T4169 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2c4433ce name:ZooKeeperConnection Watcher:127.0.0.1:52757 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1624078 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1624089 T4085 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1624095 T4171 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7caaedfe name:ZooKeeperConnection Watcher:127.0.0.1:52757/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1624095 T4085 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1624125 T4085 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1625137 T4085 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52775_
[junit4] 2> 1625140 T4085 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52775_
[junit4] 2> 1625150 T4157 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1625152 T4129 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1625152 T4171 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1625152 T4111 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1625152 T4143 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1625154 T4116 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1625174 T4085 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1625175 T4085 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1625190 T4122 oasha.CollectionsHandler.handleCreateAction Creating Collection : collection.configName=conf1&numShards=2&router.name=compositeId&wt=javabin&replicationFactor=2&version=2&router.field=myOwnField&action=CREATE&name=solrj_collection
[junit4] 2> 1625195 T4111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1625199 T4113 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.name":"compositeId",
[junit4] 2> "router.field":"myOwnField"}
[junit4] 2> 1625200 T4113 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.name":"compositeId",
[junit4] 2> "router.field":"myOwnField"}
[junit4] 2> 1625204 T4113 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection
[junit4] 2> 1625204 T4113 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 1625223 T4111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1625229 T4112 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1625231 T4112 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
[junit4] 2> 1625231 T4112 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
[junit4] 2> 1625240 T4111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1625243 T4111 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1625244 T4171 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1625244 T4143 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1625245 T4116 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1625245 T4129 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1625245 T4157 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1625324 T4113 oasc.OverseerCollectionProcessor.createCollection Creating SolrCores for new collection, shardNames [shard1, shard2] , replicationFactor : 2
[junit4] 2> 1625324 T4113 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:52775_
[junit4] 2> 1625328 T4113 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:52762_
[junit4] 2> 1625331 T4113 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:52766_
[junit4] 2> 1625336 T4165 oasha.CoreAdminHandler.handleCreateAction core create command collection=solrj_collection&collection.configName=conf1&numShards=2&wt=javabin&shard=shard1&version=2&qt=/admin/cores&action=CREATE&name=solrj_collection_shard1_replica1
[junit4] 2> 1625337 T4104 oasha.CoreAdminHandler.handleCreateAction core create command collection=solrj_collection&collection.configName=conf1&numShards=2&wt=javabin&shard=shard1&version=2&qt=/admin/cores&action=CREATE&name=solrj_collection_shard1_replica2
[junit4] 2> 1625338 T4113 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:52772_
[junit4] 2> 1625343 T4123 oasha.CoreAdminHandler.handleCreateAction core create command collection=solrj_collection&collection.configName=conf1&numShards=2&wt=javabin&shard=shard2&version=2&qt=/admin/cores&action=CREATE&name=solrj_collection_shard2_replica1
[junit4] 2> 1625345 T4104 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down collection=solrj_collection
[junit4] 2> 1625346 T4165 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down collection=solrj_collection
[junit4] 2> 1625348 T4111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1625348 T4104 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1625349 T4153 oasha.CoreAdminHandler.handleCreateAction core create command collection=solrj_collection&collection.configName=conf1&numShards=2&wt=javabin&shard=shard2&version=2&qt=/admin/cores&action=CREATE&name=solrj_collection_shard2_replica2
[junit4] 2> 1625351 T4123 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down collection=solrj_collection
[junit4] 2> 1625353 T4165 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1625355 T4111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1625355 T4123 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1625355 T4153 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down collection=solrj_collection
[junit4] 2> 1625357 T4112 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1625358 T4153 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1625358 T4112 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52762",
[junit4] 2> "core":"solrj_collection_shard1_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52762_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1625370 T4112 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52775",
[junit4] 2> "core":"solrj_collection_shard1_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52775_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1625382 T4111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1625385 T4112 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52766",
[junit4] 2> "core":"solrj_collection_shard2_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52766_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1625397 T4111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1625401 T4112 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52772",
[junit4] 2> "core":"solrj_collection_shard2_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52772_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1625411 T4111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1625519 T4157 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1625519 T4116 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1625520 T4143 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1625520 T4171 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1625519 T4129 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1625520 T4111 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1626351 T4104 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
[junit4] 2> 1626355 T4165 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
[junit4] 2> 1626357 T4123 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
[junit4] 2> 1626359 T4165 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006/solr.xml
[junit4] 2> 1626359 T4165 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 1626355 T4104 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-002/solr.xml
[junit4] 2> 1626361 T4153 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
[junit4] 2> 1626361 T4123 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003/solr.xml
[junit4] 2> 1626364 T4123 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 1626361 T4104 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 1626365 T4153 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005/solr.xml
[junit4] 2> 1626367 T4153 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 1626368 T4165 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1626368 T4165 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 1626368 T4104 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1626369 T4104 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 1626368 T4123 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1626370 T4123 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 1626369 T4153 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1626371 T4153 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 1626372 T4104 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1626372 T4104 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-002/solrj_collection_shard1_replica2/'
[junit4] 2> 1626372 T4165 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1626374 T4165 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006/solrj_collection_shard1_replica1/'
[junit4] 2> 1626378 T4123 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1626378 T4153 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1626380 T4153 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005/solrj_collection_shard2_replica2/'
[junit4] 2> 1626378 T4123 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003/solrj_collection_shard2_replica1/'
[junit4] 2> 1626534 T4123 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 1626541 T4104 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 1626592 T4153 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 1626602 T4165 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 1626731 T4123 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1626750 T4123 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1626777 T4123 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
[junit4] 2> 1626783 T4104 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1626788 T4104 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1626789 T4153 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1626800 T4165 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1626816 T4153 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1626823 T4165 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1626825 T4104 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
[junit4] 2> 1626846 T4165 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
[junit4] 2> 1626851 T4153 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
[junit4] 2> 1628862 T4153 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1628879 T4153 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1628880 T4153 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1628928 T4153 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1628941 T4153 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1629003 T4153 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1629009 T4153 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1629016 T4153 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1629020 T4153 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1629020 T4153 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1629021 T4153 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1629023 T4153 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1629024 T4153 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1629025 T4153 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using configuration from collection solrj_collection
[junit4] 2> 1629025 T4153 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1629025 T4153 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005/solrj_collection_shard2_replica2/, dataDir=./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005/solrj_collection_shard2_replica2/data/
[junit4] 2> 1629026 T4153 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@426f736c
[junit4] 2> 1629027 T4153 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005/solrj_collection_shard2_replica2/data
[junit4] 2> 1629027 T4153 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005/solrj_collection_shard2_replica2/data/index/
[junit4] 2> 1629027 T4153 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 1629036 T4153 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-005/solrj_collection_shard2_replica2/data/index
[junit4] 2> 1629038 T4153 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=7.541015625, floorSegmentMB=0.296875, forceMergeDeletesPctAllowed=2.5177052174476575, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1629041 T4123 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1629041 T4123 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1629042 T4123 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1629048 T4165 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1629048 T4165 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1629049 T4165 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1629059 T4123 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1629063 T4123 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1629064 T4153 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1b160cf3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3c90a5cb),segFN=segments_1,generation=1}
[junit4] 2> 1629064 T4153 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1629070 T4165 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1629071 T4153 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1629072 T4153 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1629073 T4153 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1629073 T4153 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1629073 T4165 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1629074 T4153 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1629074 T4153 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1629076 T4153 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1629076 T4153 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1629076 T4153 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1629078 T4153 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1629079 T4153 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1629079 T4153 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1629080 T4153 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1629081 T4153 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1629081 T4153 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1629082 T4153 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1629134 T4153 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1629142 T4153 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1629143 T4153 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1629148 T4153 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=26, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1629149 T4153 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1b160cf3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3c90a5cb),segFN=segments_1,generation=1}
[junit4] 2> 1629149 T4153 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1629150 T4153 oass.SolrIndexSearcher.<init> Opening Searcher@4571e356[solrj_collection_shard2_replica2] main
[junit4] 2> 1629150 T4153 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 1629154 T4153 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1629154 T4153 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1629157 T4153 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1629160 T4153 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1629160 T4153 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1629162 T4153 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1629163 T4153 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1629163 T4153 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1629163 T4153 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1629172 T4177 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@4571e356[solrj_collection_shard2_replica2] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1629172 T4165 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1629174 T4104 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1629174 T4104 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1629175 T4104 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1629177 T4153 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
[junit4] 2> 1629177 T4153 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:52772 collection:solrj_collection shard:shard2
[junit4] 2> 1629180 T4123 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1629185 T4104 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1629188 T4123 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1629189 T4104 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1629196 T4123 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1629198 T4153 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
[junit4] 2> 1629200 T4165 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1629202 T4123 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1629203 T4123 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1629203 T4123 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1629206 T4123 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1629206 T4123 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1629206 T4123 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using configuration from collection solrj_collection
[junit4] 2> 1629206 T4123 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1629207 T4123 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003/solrj_collection_shard2_replica1/, dataDir=./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003/solrj_collection_shard2_replica1/data/
[junit4] 2> 1629208 T4123 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@426f736c
[junit4] 2> 1629209 T4123 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003/solrj_collection_shard2_replica1/data
[junit4] 2> 1629209 T4123 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003/solrj_collection_shard2_replica1/data/index/
[junit4] 2> 1629210 T4123 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory './solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 1629206 T4165 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1629213 T4165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1629213 T4165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1629214 T4165 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1629217 T4165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1629217 T4165 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1629217 T4165 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using configuration from collection solrj_collection
[junit4] 2> 1629218 T4165 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1629218 T4165 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006/solrj_collection_shard1_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006/solrj_collection_shard1_replica1/data/
[junit4] 2> 1629219 T4165 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@426f736c
[junit4] 2> 1629220 T4165 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006/solrj_collection_shard1_replica1/data
[junit4] 2> 1629221 T4165 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006/solrj_collection_shard1_replica1/data/index/
[junit4] 2> 1629221 T4165 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 1629222 T4123 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-003/solrj_collection_shard2_replica1/data/index
[junit4] 2> 1629222 T4123 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=7.541015625, floorSegmentMB=0.296875, forceMergeDeletesPctAllowed=2.5177052174476575, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1629223 T4165 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-963C9151C73C5F1F-001/tempDir-006/solrj_collection_shard1_replica1/data/index
[junit4] 2> 1629223 T4165 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=7.541015625, floorSegmentMB=0.296875, forceMergeDeletesPctAllowed=2.5177052174476575, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1629227 T4165 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@176035a1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@13b94bfa),segFN=segments_1,generation=1}
[junit4] 2> 1629227 T4165 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1629228 T4123 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7eb3e269 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3c5654cf),segFN=segments_1,generation=1}
[junit4] 2> 1629228 T4123 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1629233 T4123 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1629235 T4123 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1629235 T4123 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1629236 T4123 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1629236 T4123 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1629236 T4123 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1629237 T4123 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1629238 T4123 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1629240 T4123 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1629240 T4123 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1629239 T4165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1629242 T4123 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1629243 T4123 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1629244 T4123 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1629243 T4165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1629245 T4123 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1629245 T4165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1629245 T4123 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1629246 T4165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1629248 T4165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1629249 T4165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1629250 T4165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1629251 T4165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1629251 T4165 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1629248 T4123 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1629252 T4165 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1629253 T4165 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1629254 T4165 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1629254 T4165 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1629255 T4165 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1629255 T4165 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1629256 T4165 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1629257 T4165 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1629249 T4153 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1629255 T4123 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1629264 T4104 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1629270 T4165 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1629270 T4165 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1629273 T4104 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1629275 T4165 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=26, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1629277 T4123 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1629278 T4123 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1629279 T4165 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@176035a1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@13b94bfa),segFN=segments_1,generation=1}
[junit4] 2> 1629279 T4165 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1629278 T4111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1629281 T4111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1629282 T4111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1629282 T4165 oass.SolrIndexSearcher.<init> Opening Searcher@7e428b4d[solrj_collection_shard1_replica1] main
[junit4] 2> 1629281 T4153 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9.327219E17ms
[junit4] 2> 1629283 T4153 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Was waiting for replicas to come up, but they are taking too long - assuming they won't come back till later
[junit4] 2> 1629284 T4153 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2265 name=solrj_collection_shard2_replica2 org.apache.solr.core.SolrCore@6172561d url=http://127.0.0.1:52772/solrj_collection_shard2_replica2 node=127.0.0.1:52772_ C2265_STATE=coll:solrj_collection core:solrj_collection_shard2_replica2 props:{state=down, base_url=http://127.0.0.1:52772, core=solrj_collection_shard2_replica2, node_name=127.0.0.1:52772_}
[junit4] 2> 1629284 T4153 C2265 P52772 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52772/solrj_collection_shard2_replica2/
[junit4] 2> 1629284 T4153 C2265 P52772 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard2_replica2 url=http://127.0.0.1:52772 START replicas=[http://127.0.0.1:52766/solrj_collection_shard2_replica1/] nUpdates=100
[junit4] 2> 1629283 T4165 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 1629284 T4123 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=26, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1629286 T4123 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7eb3e269 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3c5654cf),segFN=segments_1,generation=1}
[junit4] 2> 1629287 T4123 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1629287 T4123 oass.SolrIndexSearcher.<init> Opening Searcher@6c838de6[solrj_collection_shard2_replica1] main
[junit4] 2> 1629287 T4123 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 1629289 T4104 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1629290 T4112 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1629292 T4153 C2265 P52772 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard2_replica2 url=http://127.0.0.1:52772 DONE. We have no versions. sync failed.
[junit4] 2> 1629295 T4153 C2265 P52772 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 1629297 T4153 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 1629297 T4153 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52772/solrj_collection_shard2_replica2/ shard2
[junit4] 2> 1629298 T4153 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leaders/shard2
[junit4] 2> 1629292 T4165 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1629299 T4165 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1629296 T4123 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1629302 T4123 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1629304 T4165 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1629304 T4165 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1629304 T4165 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1629306 T4123 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1629309 T4123 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1629310 T4123 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1629303 T4104 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 162930
[...truncated too long message...]
er
[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.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 1764025 T4111 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1764164 T4214 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR Could not delete my leader node org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[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.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.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:312)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 1764166 T4129 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1764317 T4217 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[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.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 1764320 T4143 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1764493 T4220 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[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.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 1764495 T4157 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1764627 T4171 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1764627 T4171 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=sl, timezone=Europe/Athens
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_55 (64-bit)/cpus=2,threads=1,free=36402352,total=202383360
[junit4] 2> NOTE: All tests run in this JVM: [MoreLikeThisHandlerTest, TestCloudManagedSchema, TestAtomicUpdateErrorCases, StatsComponentTest, TestSweetSpotSimilarityFactory, OutputWriterTest, TestStressUserVersions, SpellCheckCollatorTest, CustomCollectionTest, TestCustomSort, PeerSyncTest, TestFieldResource, TestCloudInspectUtil, TestFastOutputStream, TestReloadAndDeleteDocs, AutoCommitTest, TestPerFieldSimilarity, TestUpdate, HdfsUnloadDistributedZkTest, BadCopyFieldTest, TestRandomFaceting, TestQueryUtils, TestStressReorder, SolrTestCaseJ4Test, HdfsSyncSliceTest, TestManagedSynonymFilterFactory, TestStandardQParsers, PreAnalyzedFieldTest, TestLuceneMatchVersion, TestDocSet, TestGroupingSearch, LeaderElectionTest, TestCollationKeyRangeQueries, HdfsWriteToMultipleCollectionsTest, DebugComponentTest, EnumFieldTest, TestReload, TestSolrQueryParserDefaultOperatorResource, TestSolrCoreProperties, TestZkChroot, CoreAdminCreateDiscoverTest, TestSolrDeletionPolicy2, ConvertedLegacyTest, TestExtendedDismaxParser, TestWriterPerf, DistanceFunctionTest, TestNonNRTOpen, SuggesterFSTTest, ChaosMonkeyNothingIsSafeTest, TestDistribDocBasedVersion, TestXIncludeConfig, StandardRequestHandlerTest, RegexBoostProcessorTest, ResourceLoaderTest, LeaderElectionIntegrationTest, QueryParsingTest, TestCollapseQParserPlugin, TestIndexSearcher, TestAnalyzeInfixSuggestions, TestDocumentBuilder, JsonLoaderTest, TestDynamicFieldResource, AtomicUpdatesTest, CSVRequestHandlerTest, TestOverriddenPrefixQueryForCustomFieldType, SolrCoreCheckLockOnStartupTest, FieldMutatingUpdateProcessorTest, ZkSolrClientTest, TestLazyCores, RequiredFieldsTest, SolrIndexSplitterTest, TestRealTimeGet, CopyFieldTest, TestRandomMergePolicy, TestConfig, TestManagedSchemaFieldResource, TestLMDirichletSimilarityFactory, BasicDistributedZk2Test, TestPHPSerializedResponseWriter, AsyncMigrateRouteKeyTest, FullSolrCloudDistribCmdsTest, DOMUtilTest, BadIndexSchemaTest, CursorMarkTest, TestManagedStopFilterFactory, DistribCursorPagingTest, TestFastWriter, DocValuesMissingTest, SimpleFacetsTest, PathHierarchyTokenizerFactoryTest, FastVectorHighlighterTest, TestNRTOpen, TestStressVersions, TestShardHandlerFactory, UUIDFieldTest, TestMiniSolrCloudCluster, SuggesterTest, TestRangeQuery, TestConfigSets, SliceStateUpdateTest, DocumentBuilderTest, OverseerStatusTest, TestCollationFieldDocValues, TestFunctionQuery, TestSolr4Spatial, ShardSplitTest, IndexSchemaRuntimeFieldTest, TestUtils, AliasIntegrationTest, LoggingHandlerTest, DistributedDebugComponentTest, ClusterStateUpdateTest, TestSchemaNameResource, CircularListTest, AlternateDirectoryTest, TestBlendedInfixSuggestions, DistributedQueryElevationComponentTest, SSLMigrationTest, SuggesterWFSTTest, IndexBasedSpellCheckerTest, TimeZoneUtilsTest, CurrencyFieldXmlFileTest, TestPhraseSuggestions, TermVectorComponentTest, DistribDocExpirationUpdateProcessorTest, HdfsDirectoryTest, TestElisionMultitermQuery, CollectionsAPIDistributedZkTest]
[junit4] Completed in 154.78s, 1 test, 1 error <<< FAILURES!
[...truncated 793 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1297: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:921: There were test failures: 389 suites, 1626 tests, 1 error, 42 ignored (15 assumptions)
Total time: 113 minutes 46 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure