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/05 23:47:18 UTC
[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.8.0_20-ea-b11) -
Build # 4011 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4011/
Java: 64bit/jdk1.8.0_20-ea-b11 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch
Error Message:
No registered leader was found after waiting for 30000ms , collection: collection1 slice: shard1
Stack Trace:
org.apache.solr.common.SolrException: No registered leader was found after waiting for 30000ms , collection: collection1 slice: shard1
at __randomizedtesting.SeedInfo.seed([E806435765ABCDD:8F66EA2D0105DCE1]:0)
at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:567)
at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.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: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 10868 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\init-core-data-001
[junit4] 2> 685152 T2786 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /mpf/kr
[junit4] 2> 685156 T2786 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 685156 T2786 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 685159 T2787 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 685262 T2786 oasc.ZkTestServer.run start zk server on port:58966
[junit4] 2> 685264 T2786 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 685269 T2793 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1377b16a name:ZooKeeperConnection Watcher:127.0.0.1:58966 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 685270 T2786 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 685270 T2786 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 685275 T2788 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145ce31f3700000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 685278 T2786 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 685280 T2795 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d2c3a39 name:ZooKeeperConnection Watcher:127.0.0.1:58966/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 685281 T2786 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 685281 T2786 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 685286 T2786 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 685292 T2786 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 685296 T2786 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 685302 T2786 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 685303 T2786 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 685311 T2786 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 685312 T2786 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 685319 T2786 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 685320 T2786 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 685340 T2786 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 685341 T2786 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 685345 T2786 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 685346 T2786 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 685351 T2786 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4] 2> 685352 T2786 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 685357 T2786 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 685358 T2786 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 685363 T2786 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 685364 T2786 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 685368 T2786 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 685369 T2786 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 685374 T2786 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 685375 T2786 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 685380 T2786 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 685381 T2786 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 687693 T2786 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 687733 T2786 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58973
[junit4] 2> 687735 T2786 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 687735 T2786 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 687736 T2786 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-002
[junit4] 2> 687736 T2786 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-002\'
[junit4] 2> 687774 T2786 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-002\solr.xml
[junit4] 2> 687789 T2786 oasc.CoreContainer.<init> New CoreContainer 1110603048
[junit4] 2> 687790 T2786 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-002\]
[junit4] 2> 687790 T2786 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 687791 T2786 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 687791 T2786 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 687791 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 687792 T2786 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 687792 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 687792 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 687792 T2786 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 687793 T2786 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 687793 T2786 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 687794 T2786 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 687794 T2786 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 687794 T2786 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58966/solr
[junit4] 2> 687795 T2786 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 687797 T2786 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 687812 T2806 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e67c7aa name:ZooKeeperConnection Watcher:127.0.0.1:58966 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 687812 T2786 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 687839 T2786 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 687843 T2808 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d45d034 name:ZooKeeperConnection Watcher:127.0.0.1:58966/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 687844 T2786 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 687846 T2786 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 687857 T2786 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 687863 T2786 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 687871 T2786 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 687881 T2786 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 687886 T2786 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 687890 T2786 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58973_mpf%2Fkr
[junit4] 2> 687892 T2786 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58973_mpf%2Fkr
[junit4] 2> 687898 T2786 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 687902 T2786 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 687913 T2786 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:58973_mpf%2Fkr
[junit4] 2> 687913 T2786 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 687918 T2786 oasc.Overseer.start Overseer (id=91706081363886083-127.0.0.1:58973_mpf%2Fkr-n_0000000000) starting
[junit4] 2> 687924 T2786 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 687946 T2810 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 687946 T2786 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 687947 T2810 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:58973_mpf%2Fkr
[junit4] 2> 687952 T2786 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 687955 T2786 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 687960 T2809 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 687965 T2811 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 687965 T2811 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 687967 T2811 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 687967 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 687970 T2809 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 687971 T2809 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:58973/mpf/kr",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58973_mpf%2Fkr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 687971 T2809 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 687971 T2809 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 687977 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 687978 T2808 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> 688996 T2811 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 688996 T2811 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 688997 T2811 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 688998 T2811 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 688999 T2811 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 689000 T2811 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-002\collection1\'
[junit4] 2> 689003 T2811 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 689005 T2811 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 689008 T2811 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 689054 T2811 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 689065 T2811 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 689068 T2811 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 689073 T2811 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 689181 T2811 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 689181 T2811 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 689184 T2811 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 689187 T2811 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 689226 T2811 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 689227 T2811 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 689229 T2811 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-002\collection1\, dataDir=.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001/control/data\
[junit4] 2> 689229 T2811 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2dab93aa
[junit4] 2> 689230 T2811 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\control\data
[junit4] 2> 689231 T2811 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001/control/data\index/
[junit4] 2> 689232 T2811 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\control\data\index' doesn't exist. Creating new index...
[junit4] 2> 689233 T2811 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\control\data\index
[junit4] 2> 689233 T2811 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=19, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1652683136746937]
[junit4] 2> 689242 T2811 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\control\data\index,segFN=segments_1,generation=1}
[junit4] 2> 689243 T2811 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 689246 T2811 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 689246 T2811 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 689247 T2811 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 689247 T2811 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 689247 T2811 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 689247 T2811 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 689248 T2811 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 689248 T2811 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 689248 T2811 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 689248 T2811 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 689249 T2811 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 689249 T2811 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 689249 T2811 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 689249 T2811 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 689250 T2811 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 689250 T2811 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 689250 T2811 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 689257 T2811 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 689260 T2811 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 689260 T2811 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 689261 T2811 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=96.6484375, floorSegmentMB=0.841796875, forceMergeDeletesPctAllowed=8.456218454293658, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 689264 T2811 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\control\data\index,segFN=segments_1,generation=1}
[junit4] 2> 689264 T2811 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 689264 T2811 oass.SolrIndexSearcher.<init> Opening Searcher@532ccf5c[collection1] main
[junit4] 2> 689265 T2811 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 689267 T2811 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 689268 T2811 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 689269 T2811 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 689269 T2811 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 689269 T2811 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 689270 T2811 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 689270 T2811 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 689271 T2811 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 689271 T2811 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 689273 T2812 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@532ccf5c[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 689274 T2811 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 689276 T2815 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58973/mpf/kr collection:control_collection shard:shard1
[junit4] 2> 689276 T2786 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 689278 T2786 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 689278 T2815 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 689283 T2786 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 689286 T2817 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c9ead85 name:ZooKeeperConnection Watcher:127.0.0.1:58966/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 689286 T2786 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 689291 T2786 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 689298 T2786 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 689300 T2815 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 689304 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 689305 T2815 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 689305 T2815 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C382 name=collection1 org.apache.solr.core.SolrCore@43d4611 url=http://127.0.0.1:58973/mpf/kr/collection1 node=127.0.0.1:58973_mpf%2Fkr C382_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:58973/mpf/kr, core=collection1, node_name=127.0.0.1:58973_mpf%2Fkr}
[junit4] 2> 689305 T2815 C382 P58973 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58973/mpf/kr/collection1/
[junit4] 2> 689307 T2815 C382 P58973 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 689307 T2815 C382 P58973 oasc.SyncStrategy.syncToMe http://127.0.0.1:58973/mpf/kr/collection1/ has no replicas
[junit4] 2> 689307 T2815 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58973/mpf/kr/collection1/ shard1
[junit4] 2> 689307 T2815 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 689310 T2809 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 689332 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 689336 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 689343 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 689453 T2817 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> 689454 T2808 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> 689495 T2815 oasc.ZkController.register We are http://127.0.0.1:58973/mpf/kr/collection1/ and leader is http://127.0.0.1:58973/mpf/kr/collection1/
[junit4] 2> 689495 T2815 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58973/mpf/kr
[junit4] 2> 689495 T2815 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 689495 T2815 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 689495 T2815 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 689508 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 689508 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 689508 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 689508 T2815 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 689640 T2809 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 689736 T2809 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:58973/mpf/kr",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58973_mpf%2Fkr",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 689753 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 689861 T2817 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> 689861 T2808 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> 691495 T2786 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 691496 T2786 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 691499 T2786 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58985
[junit4] 2> 691500 T2786 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 691500 T2786 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 691500 T2786 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-003
[junit4] 2> 691500 T2786 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-003\'
[junit4] 2> 691529 T2786 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-003\solr.xml
[junit4] 2> 691541 T2786 oasc.CoreContainer.<init> New CoreContainer 502861802
[junit4] 2> 691541 T2786 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-003\]
[junit4] 2> 691544 T2786 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 691544 T2786 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 691545 T2786 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 691545 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 691545 T2786 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 691545 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 691545 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 691545 T2786 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 691545 T2786 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 691545 T2786 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 691545 T2786 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 691545 T2786 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 691545 T2786 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58966/solr
[junit4] 2> 691545 T2786 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 691549 T2786 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 691564 T2828 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16443601 name:ZooKeeperConnection Watcher:127.0.0.1:58966 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 691565 T2786 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 691576 T2788 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145ce31f3700005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 691577 T2786 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 691580 T2830 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ffd3542 name:ZooKeeperConnection Watcher:127.0.0.1:58966/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 691580 T2786 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 691595 T2786 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 692633 T2786 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58985_mpf%2Fkr
[junit4] 2> 692637 T2786 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58985_mpf%2Fkr
[junit4] 2> 692667 T2831 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 692668 T2831 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 692672 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 692672 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 692672 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 692677 T2831 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 692681 T2809 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 692682 T2809 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:58985/mpf/kr",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58985_mpf%2Fkr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 692682 T2809 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 692682 T2809 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 692690 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 692693 T2817 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> 692694 T2808 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> 692694 T2830 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> 693706 T2831 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 693706 T2831 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 693708 T2831 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 693708 T2831 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 693710 T2831 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 693710 T2831 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-003\collection1\'
[junit4] 2> 693712 T2831 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 693712 T2831 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 693716 T2831 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 693763 T2831 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 693773 T2831 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 693777 T2831 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 693783 T2831 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 693892 T2831 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 693892 T2831 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 693895 T2831 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 693900 T2831 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 693934 T2831 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 693934 T2831 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 693934 T2831 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-003\collection1\, dataDir=.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001/jetty1\
[junit4] 2> 693935 T2831 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2dab93aa
[junit4] 2> 693936 T2831 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty1
[junit4] 2> 693937 T2831 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001/jetty1\index/
[junit4] 2> 693938 T2831 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty1\index' doesn't exist. Creating new index...
[junit4] 2> 693938 T2831 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty1\index
[junit4] 2> 693938 T2831 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=19, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1652683136746937]
[junit4] 2> 693944 T2831 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty1\index,segFN=segments_1,generation=1}
[junit4] 2> 693944 T2831 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 693949 T2831 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 693950 T2831 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 693950 T2831 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 693950 T2831 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 693951 T2831 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 693951 T2831 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 693951 T2831 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 693952 T2831 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 693952 T2831 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 693952 T2831 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 693953 T2831 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 693953 T2831 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 693953 T2831 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 693955 T2831 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 693955 T2831 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 693956 T2831 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 693956 T2831 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 693962 T2831 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 693965 T2831 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 693965 T2831 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 693966 T2831 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=96.6484375, floorSegmentMB=0.841796875, forceMergeDeletesPctAllowed=8.456218454293658, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 693966 T2831 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty1\index,segFN=segments_1,generation=1}
[junit4] 2> 693966 T2831 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 693969 T2831 oass.SolrIndexSearcher.<init> Opening Searcher@2e2cb17e[collection1] main
[junit4] 2> 693969 T2831 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 693971 T2831 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 693971 T2831 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 693972 T2831 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 693972 T2831 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 693973 T2831 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 693974 T2831 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 693975 T2831 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 693975 T2831 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 693976 T2831 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 693980 T2832 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2e2cb17e[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 693983 T2831 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 693984 T2835 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58985/mpf/kr collection:collection1 shard:shard2
[junit4] 2> 693985 T2786 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 693985 T2786 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 693986 T2835 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 694000 T2835 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 694004 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 694005 T2835 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 694005 T2835 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C383 name=collection1 org.apache.solr.core.SolrCore@65c5bef1 url=http://127.0.0.1:58985/mpf/kr/collection1 node=127.0.0.1:58985_mpf%2Fkr C383_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:58985/mpf/kr, core=collection1, node_name=127.0.0.1:58985_mpf%2Fkr}
[junit4] 2> 694005 T2835 C383 P58985 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58985/mpf/kr/collection1/
[junit4] 2> 694005 T2835 C383 P58985 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 694005 T2835 C383 P58985 oasc.SyncStrategy.syncToMe http://127.0.0.1:58985/mpf/kr/collection1/ has no replicas
[junit4] 2> 694005 T2835 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58985/mpf/kr/collection1/ shard2
[junit4] 2> 694007 T2835 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 694011 T2809 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 694019 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 694023 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 694030 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 694142 T2817 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> 694142 T2808 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> 694143 T2830 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> 694182 T2835 oasc.ZkController.register We are http://127.0.0.1:58985/mpf/kr/collection1/ and leader is http://127.0.0.1:58985/mpf/kr/collection1/
[junit4] 2> 694182 T2835 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58985/mpf/kr
[junit4] 2> 694182 T2835 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 694182 T2835 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 694182 T2835 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 694186 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 694186 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 694186 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 694188 T2835 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 694190 T2809 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 694193 T2809 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:58985/mpf/kr",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58985_mpf%2Fkr",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 694199 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 694308 T2830 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> 694309 T2817 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> 694309 T2808 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> 696296 T2786 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 696296 T2786 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 696301 T2786 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58994
[junit4] 2> 696301 T2786 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 696301 T2786 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 696301 T2786 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-004
[junit4] 2> 696301 T2786 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-004\'
[junit4] 2> 696343 T2786 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-004\solr.xml
[junit4] 2> 696363 T2786 oasc.CoreContainer.<init> New CoreContainer 255337494
[junit4] 2> 696364 T2786 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-004\]
[junit4] 2> 696364 T2786 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 696364 T2786 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 696365 T2786 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 696365 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 696365 T2786 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 696367 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 696367 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 696367 T2786 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 696367 T2786 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 696368 T2786 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 696368 T2786 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 696369 T2786 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 696369 T2786 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58966/solr
[junit4] 2> 696370 T2786 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 696372 T2786 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 696382 T2846 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5825b22b name:ZooKeeperConnection Watcher:127.0.0.1:58966 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 696383 T2786 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 696392 T2786 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 696395 T2848 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ad90757 name:ZooKeeperConnection Watcher:127.0.0.1:58966/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 696396 T2786 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 696412 T2786 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 697550 T2786 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58994_mpf%2Fkr
[junit4] 2> 697552 T2786 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58994_mpf%2Fkr
[junit4] 2> 697570 T2849 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 697570 T2849 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 697572 T2849 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 697572 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 697572 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 697573 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 697574 T2809 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 697575 T2809 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:58994/mpf/kr",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58994_mpf%2Fkr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 697576 T2809 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 697576 T2809 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 697581 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 697583 T2830 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> 697583 T2817 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> 697583 T2808 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> 697583 T2848 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> 698704 T2849 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 698704 T2849 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 698705 T2849 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 698705 T2849 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 698708 T2849 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 698709 T2849 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-004\collection1\'
[junit4] 2> 698711 T2849 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 698714 T2849 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 698715 T2849 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 698756 T2849 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 698769 T2849 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 698771 T2849 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 698777 T2849 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 698894 T2849 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 698894 T2849 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 698897 T2849 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 698902 T2849 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 698936 T2849 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 698936 T2849 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 698937 T2849 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-004\collection1\, dataDir=.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001/jetty2\
[junit4] 2> 698937 T2849 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2dab93aa
[junit4] 2> 698938 T2849 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty2
[junit4] 2> 698939 T2849 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001/jetty2\index/
[junit4] 2> 698940 T2849 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty2\index' doesn't exist. Creating new index...
[junit4] 2> 698940 T2849 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty2\index
[junit4] 2> 698941 T2849 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=19, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1652683136746937]
[junit4] 2> 698947 T2849 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty2\index,segFN=segments_1,generation=1}
[junit4] 2> 698947 T2849 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 698952 T2849 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 698952 T2849 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 698953 T2849 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 698953 T2849 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 698953 T2849 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 698954 T2849 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 698954 T2849 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 698955 T2849 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 698955 T2849 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 698955 T2849 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 698957 T2849 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 698957 T2849 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 698957 T2849 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 698958 T2849 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 698958 T2849 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 698958 T2849 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 698960 T2849 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 698965 T2849 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 698968 T2849 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 698968 T2849 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 698971 T2849 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=96.6484375, floorSegmentMB=0.841796875, forceMergeDeletesPctAllowed=8.456218454293658, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 698972 T2849 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty2\index,segFN=segments_1,generation=1}
[junit4] 2> 698972 T2849 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 698973 T2849 oass.SolrIndexSearcher.<init> Opening Searcher@56f438d2[collection1] main
[junit4] 2> 698973 T2849 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 698975 T2849 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 698975 T2849 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 698976 T2849 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 698976 T2849 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 698976 T2849 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 698978 T2849 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 698978 T2849 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 698978 T2849 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 698978 T2849 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 698983 T2849 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 698984 T2850 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@56f438d2[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 698986 T2853 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58994/mpf/kr collection:collection1 shard:shard1
[junit4] 2> 698988 T2786 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 698988 T2786 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 698992 T2853 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 699005 T2853 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 699010 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 699012 T2853 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 699012 T2853 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C384 name=collection1 org.apache.solr.core.SolrCore@36a01273 url=http://127.0.0.1:58994/mpf/kr/collection1 node=127.0.0.1:58994_mpf%2Fkr C384_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:58994/mpf/kr, core=collection1, node_name=127.0.0.1:58994_mpf%2Fkr}
[junit4] 2> 699012 T2853 C384 P58994 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58994/mpf/kr/collection1/
[junit4] 2> 699012 T2853 C384 P58994 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 699012 T2853 C384 P58994 oasc.SyncStrategy.syncToMe http://127.0.0.1:58994/mpf/kr/collection1/ has no replicas
[junit4] 2> 699014 T2853 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58994/mpf/kr/collection1/ shard1
[junit4] 2> 699014 T2853 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 699018 T2809 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 699030 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 699034 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 699041 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 699160 T2830 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> 699171 T2848 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> 699171 T2808 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> 699171 T2817 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> 699209 T2853 oasc.ZkController.register We are http://127.0.0.1:58994/mpf/kr/collection1/ and leader is http://127.0.0.1:58994/mpf/kr/collection1/
[junit4] 2> 699209 T2853 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58994/mpf/kr
[junit4] 2> 699209 T2853 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 699209 T2853 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 699209 T2853 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 699211 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 699211 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 699211 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 699214 T2853 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 699216 T2809 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 699219 T2809 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:58994/mpf/kr",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58994_mpf%2Fkr",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 699225 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 699344 T2830 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> 699344 T2817 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> 699345 T2808 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> 699344 T2848 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> 701346 T2786 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 701347 T2786 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 701352 T2786 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:59003
[junit4] 2> 701352 T2786 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 701352 T2786 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 701352 T2786 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-005
[junit4] 2> 701355 T2786 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-005\'
[junit4] 2> 701388 T2786 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-005\solr.xml
[junit4] 2> 701416 T2786 oasc.CoreContainer.<init> New CoreContainer 1635822548
[junit4] 2> 701416 T2786 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-005\]
[junit4] 2> 701417 T2786 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 701417 T2786 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 701417 T2786 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 701417 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 701417 T2786 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 701417 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 701417 T2786 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 701417 T2786 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 701419 T2786 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 701419 T2786 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 701419 T2786 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 701419 T2786 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 701422 T2786 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58966/solr
[junit4] 2> 701422 T2786 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 701424 T2786 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 701450 T2864 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bcf33b2 name:ZooKeeperConnection Watcher:127.0.0.1:58966 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 701453 T2786 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 701461 T2786 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 701464 T2866 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b2d34b2 name:ZooKeeperConnection Watcher:127.0.0.1:58966/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 701464 T2786 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 701479 T2786 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 702618 T2786 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59003_mpf%2Fkr
[junit4] 2> 702620 T2786 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59003_mpf%2Fkr
[junit4] 2> 702639 T2867 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 702639 T2867 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 702641 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 702641 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 702641 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 702643 T2867 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 702645 T2809 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 702647 T2809 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:59003/mpf/kr",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59003_mpf%2Fkr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 702647 T2809 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 702647 T2809 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 702654 T2808 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 702656 T2830 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> 702656 T2848 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> 702657 T2817 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> 702656 T2866 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> 702657 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> 703775 T2867 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 703775 T2867 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 703778 T2867 oasc.ZkController.createCollectionZkNode Collection zkNo
[...truncated too long message...]
pDir-001\jetty6\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty6\index;done=false>>]
[junit4] 2> 801172 T2930 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty6\index
[junit4] 2> 801173 T2930 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> 801173 T2930 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 801174 T2951 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=51,cumulative_deletesById=24,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=5869,transaction_logs_total_number=1}
[junit4] 2> 801174 T2951 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 801174 T2951 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 801174 T2951 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 801179 T2951 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 801179 T2951 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 801179 T2951 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty7\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty7\index;done=false>>]
[junit4] 2> 801179 T2951 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty7\index
[junit4] 2> 801179 T2951 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty7 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty7;done=false>>]
[junit4] 2> 801179 T2951 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001\tempDir-001\jetty7
[junit4] 2> 801179 T2951 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 801179 T2951 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> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.ChaosMonkeyNothingIsSafeTest-E806435765ABCDD-001
[junit4] 2> NOTE: test params are: codec=Lucene46: {rnd_b=PostingsFormat(name=SimpleText), _version_=Pulsing41(freqCutoff=1 minBlockSize=25 maxBlockSize=139), a_t=PostingsFormat(name=Lucene41VarGapFixedInterval), a_i=PostingsFormat(name=SimpleText), id=PostingsFormat(name=SimpleText)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=sk_SK, timezone=Europe/Lisbon
[junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.8.0_20-ea (64-bit)/cpus=2,threads=1,free=47102136,total=269484032
[junit4] 2> NOTE: All tests run in this JVM: [XsltUpdateRequestHandlerTest, BasicDistributedZk2Test, EchoParamsTest, ReturnFieldsTest, TestSolrJ, DocumentBuilderTest, TestRTGBase, TestLFUCache, AliasIntegrationTest, CoreMergeIndexesAdminHandlerTest, ExternalFileFieldSortTest, ClusterStateUpdateTest, TestMultiCoreConfBootstrap, TriLevelCompositeIdRoutingTest, AlternateDirectoryTest, PreAnalyzedFieldTest, TestNonNRTOpen, TestWriterPerf, NoFacetTest, TestSolrQueryParserResource, TestClassNameShortening, TestImplicitCoreProperties, TestInfoStreamLogging, StressHdfsTest, BadIndexSchemaTest, CoreAdminRequestStatusTest, TestStressLucene, TestFreeTextSuggestions, TestSolrIndexConfig, TestFaceting, LukeRequestHandlerTest, TestManagedSchemaFieldResource, TestCustomSort, SolrPluginUtilsTest, TestRandomMergePolicy, TestStandardQParsers, DefaultValueUpdateProcessorTest, TestExceedMaxTermLength, BinaryUpdateRequestHandlerTest, MoreLikeThisHandlerTest, UpdateRequestProcessorFactoryTest, PluginInfoTest, TestCollationField, TestRandomDVFaceting, CursorMarkTest, AutoCommitTest, TestOverriddenPrefixQueryForCustomFieldType, TestRandomFaceting, TermVectorComponentTest, SoftAutoCommitTest, AsyncMigrateRouteKeyTest, SolrInfoMBeanTest, AnalysisAfterCoreReloadTest, TestSchemaSimilarityResource, TestFieldResource, TestFieldTypeResource, OutputWriterTest, TestTrie, TestJoin, DirectSolrConnectionTest, TestSurroundQueryParser, TestConfig, CopyFieldTest, SpatialFilterTest, TestUniqueKeyFieldResource, StatelessScriptUpdateProcessorFactoryTest, TestOmitPositions, TestCharFilters, SampleTest, TestQuerySenderListener, TestCoreContainer, TestHighFrequencyDictionaryFactory, TestReplicationHandler, TestManagedStopFilterFactory, TestCollectionAPI, ZkNodePropsTest, SolrXmlInZkTest, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed in 117.04s, 1 test, 1 error <<< FAILURES!
[...truncated 994 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1296: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:920: There were test failures: 398 suites, 1673 tests, 1 error, 42 ignored (21 assumptions)
Total time: 86 minutes 23 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0_20-ea-b11 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.7.0_60-ea-b15) -
Build # 4012 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4012/
Java: 32bit/jdk1.7.0_60-ea-b15 -server -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([F2528910C9BC59CB:F65A06E3DB19B6EA]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
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)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
... 46 more
Build Log:
[...truncated 10748 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-F2528910C9BC59CB-001\init-core-data-001
[junit4] 2> 796738 T2432 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 796738 T2432 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 796738 T2432 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 796754 T2432 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 796757 T2432 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 796758 T2433 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 796908 T2432 oasc.ZkTestServer.run start zk server on port:55196
[junit4] 2> 796915 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 796928 T2439 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19463c8 name:ZooKeeperConnection Watcher:127.0.0.1:55196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 796930 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 796937 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 796945 T2441 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27e80 name:ZooKeeperConnection Watcher:127.0.0.1:55196 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 796945 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 796953 T2434 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2767f0001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 796956 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 796968 T2443 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fd2442 name:ZooKeeperConnection Watcher:127.0.0.1:55196 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 796968 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 796968 T2432 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 796986 T2432 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 796987 T2434 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2767f0002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 797003 T2432 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 797015 T2432 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 797024 T2432 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 797040 T2432 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 797065 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 797073 T2445 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18594e7 name:ZooKeeperConnection Watcher:127.0.0.1:55196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 797073 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 797078 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 797091 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 797113 T2432 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55196_solr
[junit4] 2> 797113 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 797126 T2432 oasc.Overseer.start Overseer (id=91708007708033027-127.0.0.1:55196_solr-n_0000000000) starting
[junit4] 2> 797136 T2432 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 797161 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 797177 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 797196 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 797217 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 797246 T2447 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 797251 T2447 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:55196_solr
[junit4] 2> 797262 T2446 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 797265 T2446 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 797268 T2446 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 797273 T2439 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 797290 T2446 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 797296 T2439 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 797308 T2446 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 797318 T2446 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 797321 T2446 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 797336 T2445 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 797495 T2439 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 797566 T2434 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2767f0003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 797571 T2434 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2767f0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 797573 T2432 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55196 55196
[junit4] 2> 800954 T2433 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55196 55196
[junit4] 2> 800957 T2432 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 800958 T2446 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:55196_solr
[junit4] 2> 800961 T2448 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 800970 T2432 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 800974 T2432 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 800976 T2449 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 801125 T2432 oasc.ZkTestServer.run start zk server on port:55211
[junit4] 2> 801129 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 801137 T2455 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bd8f4a name:ZooKeeperConnection Watcher:127.0.0.1:55211 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 801138 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 801143 T2450 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff286f50000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 801147 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 801151 T2457 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@108708c name:ZooKeeperConnection Watcher:127.0.0.1:55211 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 801151 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 801151 T2432 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 801165 T2450 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff286f50001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 801168 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 801170 T2459 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a07d55 name:ZooKeeperConnection Watcher:127.0.0.1:55211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 801172 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 801172 T2432 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 801181 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 801187 T2461 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1da24cc name:ZooKeeperConnection Watcher:127.0.0.1:55211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 801187 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 801189 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 801197 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 801209 T2432 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55211_solr
[junit4] 2> 801209 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 801216 T2432 oasc.Overseer.start Overseer (id=91708007984201731-127.0.0.1:55211_solr-n_0000000000) starting
[junit4] 2> 801220 T2432 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 801229 T2432 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 801239 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 801248 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 801257 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 801272 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 801288 T2463 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 801289 T2432 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 801291 T2463 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:55211_solr
[junit4] 2> 801291 T2462 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 801296 T2432 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 801301 T2432 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 801311 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 801318 T2465 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e5938 name:ZooKeeperConnection Watcher:127.0.0.1:55211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 801318 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 801323 T2432 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 801329 T2432 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 801345 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 801349 T2462 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 801351 T2462 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 801351 T2462 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 801352 T2462 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 801359 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 801362 T2459 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> 801362 T2465 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> 802096 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 802153 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 802175 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 802183 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 802184 T2462 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 802197 T2462 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 802197 T2462 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 802197 T2462 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 802206 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 802361 T2459 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> 802363 T2465 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> 802934 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 802975 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 803004 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 803004 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 803006 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 803013 T2462 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 803016 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 803037 T2462 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 803037 T2462 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 803037 T2462 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 803053 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 803218 T2465 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> 803220 T2459 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> 803766 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 803810 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 803839 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 803839 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 803841 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 803850 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 803852 T2462 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 803876 T2462 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node4",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 803876 T2462 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 803876 T2462 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 803892 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 804053 T2465 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> 804055 T2459 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> 804602 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 804629 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 804630 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 804630 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 804635 T2462 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 804636 T2462 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core5",
[junit4] 2> "core_node_name":"node5",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 804636 T2462 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 804636 T2462 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 804643 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 804802 T2465 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> 804802 T2459 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> 805380 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 805405 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 805407 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 805407 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 805411 T2462 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 805413 T2462 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 805413 T2462 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 805414 T2462 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 805420 T2461 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 805578 T2459 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> 805578 T2465 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> 806157 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 806177 T2450 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff286f50002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 806190 T2450 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff286f50003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 806190 T2432 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55211 55211
[junit4] 2> 808436 T2465 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/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> 809568 T2465 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/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> 809568 T2465 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/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> 809574 T2449 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55211 55211
[junit4] 2> 809577 T2432 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 809578 T2462 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:55211_solr
[junit4] 2> 809583 T2466 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 809589 T2432 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 809593 T2432 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 809595 T2467 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 809745 T2432 oasc.ZkTestServer.run start zk server on port:55229
[junit4] 2> 809750 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 809769 T2473 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@857c7b name:ZooKeeperConnection Watcher:127.0.0.1:55229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 809770 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 809773 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 809776 T2475 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1853360 name:ZooKeeperConnection Watcher:127.0.0.1:55229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 809778 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 809782 T2468 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2a8a40001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 809785 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 809788 T2477 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@84bf94 name:ZooKeeperConnection Watcher:127.0.0.1:55229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 809788 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 809788 T2432 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 809797 T2432 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 809797 T2468 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2a8a40002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 809804 T2432 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 809808 T2432 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 809813 T2432 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 809820 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 809824 T2479 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@187a4c9 name:ZooKeeperConnection Watcher:127.0.0.1:55229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 809824 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 809827 T2432 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 809832 T2432 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 809841 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 809845 T2481 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c610fa name:ZooKeeperConnection Watcher:127.0.0.1:55229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 809845 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 809846 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 809852 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 809861 T2432 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55229_solr
[junit4] 2> 809861 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 809867 T2432 oasc.Overseer.start Overseer (id=91708008549318660-127.0.0.1:55229_solr-n_0000000000) starting
[junit4] 2> 809871 T2432 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 809879 T2432 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 809887 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 809895 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 809905 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 809914 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 809930 T2483 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 809933 T2483 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:55229_solr
[junit4] 2> 809934 T2482 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 809940 T2482 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 809942 T2482 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 809942 T2482 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 809943 T2482 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 809950 T2481 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 809953 T2479 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> 809953 T2473 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> 810686 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 810736 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 810769 T2481 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 810775 T2432 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 810777 T2482 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 810791 T2468 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2a8a40003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 810799 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 810803 T2481 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 810807 T2485 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6febad name:ZooKeeperConnection Watcher:127.0.0.1:55229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 810810 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 810815 T2432 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 810822 T2432 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 810834 T2481 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 810834 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 810837 T2482 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 810837 T2482 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 810841 T2481 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 810850 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 810863 T2481 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 810870 T2481 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 811026 T2473 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> 811026 T2485 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> 811029 T2432 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 811046 T2468 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2a8a40000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 811048 T2432 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55229 55229
[junit4] 2> 813100 T2482 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work/qn-0000000002
[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.DistributedQueue.remove(DistributedQueue.java:178)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:493)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:265)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 814125 T2482 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:55229_solr
[junit4] 2> 814130 T2486 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 814130 T2467 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55229 55229
[junit4] 2> 814134 T2432 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 814144 T2432 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 814147 T2432 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 814148 T2487 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 814284 T2432 oasc.ZkTestServer.run start zk server on port:55250
[junit4] 2> 814288 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 814296 T2493 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@883f0a name:ZooKeeperConnection Watcher:127.0.0.1:55250/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 814297 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 814299 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 814302 T2495 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18389f4 name:ZooKeeperConnection Watcher:127.0.0.1:55250 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 814302 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 814308 T2488 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2ba690001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 814309 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 814312 T2497 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1becba6 name:ZooKeeperConnection Watcher:127.0.0.1:55250 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 814313 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 814313 T2432 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 814320 T2432 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 814321 T2488 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2ba690002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 814326 T2432 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 814330 T2432 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 814334 T2432 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 814341 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 814343 T2499 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bf7f16 name:ZooKeeperConnection Watcher:127.0.0.1:55250/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 814345 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 814347 T2432 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 814351 T2432 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 814360 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 814364 T2501 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19a0dd6 name:ZooKeeperConnection Watcher:127.0.0.1:55250/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 814364 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 814366 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 814372 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 814382 T2432 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55250_solr
[junit4] 2> 814383 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 814387 T2432 oasc.Overseer.start Overseer (id=91708008847441924-127.0.0.1:55250_solr-n_0000000000) starting
[junit4] 2> 814392 T2432 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 814400 T2432 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 814408 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 814417 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 814425 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 814434 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 814458 T2503 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 814462 T2503 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:55250_solr
[junit4] 2> 814463 T2502 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 814471 T2502 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 814474 T2502 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 814474 T2502 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 814474 T2502 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 814486 T2501 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 814490 T2499 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> 814490 T2493 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> 815140 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 815161 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 815173 T2501 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 815174 T2432 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 815177 T2502 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 815186 T2488 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2ba690000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 815187 T2432 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55250 55250
[junit4] 2> 817201 T2502 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /clusterstate.json
[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.common.cloud.ClusterState.load(ClusterState.java:239)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:445)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:242)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:234)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 818224 T2502 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:55250_solr
[junit4] 2> 818227 T2487 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55250 55250
[junit4] 2> 818228 T2504 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 818230 T2432 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 2> 818238 T2432 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 818242 T2432 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 818243 T2505 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 818377 T2432 oasc.ZkTestServer.run start zk server on port:55268
[junit4] 2> 818383 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 818398 T2511 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bc793a name:ZooKeeperConnection Watcher:127.0.0.1:55268/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 818400 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 818405 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 818412 T2513 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13a9dd name:ZooKeeperConnection Watcher:127.0.0.1:55268 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 818413 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 818423 T2506 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2ca680001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 818426 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 818433 T2515 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@109eebd name:ZooKeeperConnection Watcher:127.0.0.1:55268 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 818434 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 818434 T2432 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 818447 T2432 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 818447 T2506 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2ca680002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 818455 T2432 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 818460 T2432 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 818464 T2432 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 818472 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 818475 T2517 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1644641 name:ZooKeeperConnection Watcher:127.0.0.1:55268/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 818475 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 818478 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 818481 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 818491 T2432 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55268_solr
[junit4] 2> 818491 T2432 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 818496 T2432 oasc.Overseer.start Overseer (id=91708009115811843-127.0.0.1:55268_solr-n_0000000000) starting
[junit4] 2> 818500 T2432 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 818509 T2432 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 818517 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 818524 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 818530 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 818538 T2432 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 818551 T2519 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 818554 T2518 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 818554 T2519 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:55268_solr
[junit4] 2> 818559 T2432 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 818562 T2518 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 818563 T2518 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 818563 T2518 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 818569 T2517 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 818571 T2511 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 818630 T2432 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 818634 T2517 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 818638 T2518 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 818640 T2518 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 818640 T2518 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 818640 T2518 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 818646 T2517 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 818785 T2511 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 818851 T2506 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2ca680000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 818853 T2432 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55268 55268
[junit4] 2> 821897 T2505 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55268 55268
[junit4] 2> 821902 T2432 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 821904 T2518 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:55268_solr
[junit4] 2> 821912 T2520 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 821921 T2432 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 821928 T2432 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 821930 T2521 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 822065 T2432 oasc.ZkTestServer.run start zk server on port:55283
[junit4] 2> 822070 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 822078 T2527 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c0fa9 name:ZooKeeperConnection Watcher:127.0.0.1:55283/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 822079 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 822082 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 822086 T2529 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14df2df name:ZooKeeperConnection Watcher:127.0.0.1:55283 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 822086 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 822091 T2522 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2d8d20001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 822094 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 822098 T2531 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f2e65 name:ZooKeeperConnection Watcher:127.0.0.1:55283 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 822098 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 822098 T2432 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 822107 T2432 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 822107 T2522 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff2d8d20002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 822116 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 822117 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 822120 T2534 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b26870 name:ZooKeeperConnection Watcher:127.0.0.1:55283/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 822121 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 822123 T2536 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4684b4 name:ZooKeeperConnection Watcher:127.0.0.1:55283/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 822123 T2532 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 822124 T2432 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 822125 T2432 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 822131 T2532 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 822132 T2432 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 822138 T2432 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 822146 T2532 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55283_solr
[junit4] 2> 822146 T2532 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 822149 T2432 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 822153 T2532 oasc.Overseer.start Overseer (id=91708009357639683-127.0.0.1:55283_solr-n_0000000000) starting
[junit4] 2> 822162 T2532 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 822164 T2432 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 822171 T2532 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 822179 T2532 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 822189 T2532 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 822196 T2532 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 822206 T2532 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 822220 T2532 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 822222 T2538 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 822251 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 822254 T2540 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fcd0ef name:ZooKeeperConnection Watcher:127.0.0.1:55283/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 822254 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 822256 T2538 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91708009357639683-127.0.0.1:55283_solr-n_0000000000) am no longer a leader.
[junit4] 2> 822257 T2538 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:55283_solr
[junit4] 2> 822258 T2538 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[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.exists(ZooKeeper.java:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:293)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:206)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 822266 T2532 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55283_solr
[junit4] 2> 822266 T2532 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 822272 T2532 oasc.Overseer.start Overseer (id=91708009357639685-127.0.0.1:55283_solr-n_0000000001) starting
[junit4] 2> 822306 T2542 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 822307 T2542 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:55283_solr
[junit4] 2> 822309 T2541 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 822314 T2541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 822315 T2541 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 822315 T2541 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 822315 T2541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 822322 T2540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 822323 T2536 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> 822846 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 822879 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 822895 T2540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 822899 T2540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 822900 T2541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 822900 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 822914 T2541 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 822914 T2541 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 822918 T2432 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 822922 T2540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 822922 T2544 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@eb626d n
[...truncated too long message...]
junit4] 2> 863263 T2793 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 863263 T2793 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 863263 T2793 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 863268 T2792 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 863360 T2790 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> 863360 T2796 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> 863699 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 863721 T2432 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 863737 T2792 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 863738 T2792 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 863738 T2792 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 863743 T2793 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 863755 T2792 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 863848 T2796 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> 863849 T2790 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> 863876 T2781 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff36fb00002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 863880 T2781 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff36fb00004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 863883 T2781 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145cff36fb00003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 863883 T2432 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55538 55538
[junit4] 2> 865879 T2780 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55538 55538
[junit4] 2> 865881 T2432 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 865882 T2793 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:55538_solr
[junit4] 2> 865884 T2797 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 865884 T2432 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 865886 T2432 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 868389 T2432 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-F2528910C9BC59CB-001
[junit4] 2> NOTE: test params are: codec=Lucene45, sim=DefaultSimilarity, locale=fr_LU, timezone=Africa/Sao_Tome
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=2,threads=1,free=68111496,total=225419264
[junit4] 2> NOTE: All tests run in this JVM: [IndexSchemaRuntimeFieldTest, TestSolrDeletionPolicy2, TestOverriddenPrefixQueryForCustomFieldType, TestSolr4Spatial, TestRandomFaceting, TestWordDelimiterFilterFactory, OverseerRolesTest, SolrCoreCheckLockOnStartupTest, HighlighterConfigTest, TestManagedResource, SpellCheckComponentTest, AnalysisErrorHandlingTest, BasicDistributedZkTest, ConnectionManagerTest, TestReloadAndDeleteDocs, SSLMigrationTest, TestFieldTypeResource, TestJmxIntegration, ResponseLogComponentTest, TestNoOpRegenerator, TestDynamicFieldResource, TestSystemIdResolver, PrimitiveFieldTypeTest, TestBadConfig, TestCursorMarkWithoutUniqueKey, UUIDFieldTest, DocValuesTest, RegexBoostProcessorTest, PrimUtilsTest, SuggesterTest, TestQueryUtils, TestStressLucene, SolrCoreTest, TestModifyConfFiles, TestAnalyzeInfixSuggestions, DisMaxRequestHandlerTest, TestDefaultSearchFieldResource, FunctionTest, TestLFUCache, InfoHandlerTest, SynonymTokenizerTest, BadIndexSchemaTest, AssignTest, BadCopyFieldTest, TestInitQParser, SolrIndexSplitterTest, TestFoldingMultitermQuery, FileBasedSpellCheckerTest, LoggingHandlerTest, QueryElevationComponentTest, DocExpirationUpdateProcessorFactoryTest, TestSimpleQParserPlugin, PolyFieldTest, SolrInfoMBeanTest, EnumFieldTest, TestIBSimilarityFactory, TestAtomicUpdateErrorCases, SuggesterWFSTTest, CSVRequestHandlerTest, DistributedSuggestComponentTest, TestCloudManagedSchemaAddField, TestSearcherReuse, TestRemoteStreaming, TestRequestStatusCollectionAPI, TestArbitraryIndexDir, TestPostingsSolrHighlighter, ShardRoutingCustomTest, SuggesterFSTTest, DistributedQueryElevationComponentTest, TestFastWriter, OutputWriterTest, SystemInfoHandlerTest, TestQuerySenderNoQuery, NoCacheHeaderTest, TestFiltering, TestAddFieldRealTimeGet, SolrPluginUtilsTest, TestHashPartitioner, ResourceLoaderTest, DateFieldTest, DistribCursorPagingTest, SpellCheckCollatorTest, HdfsSyncSliceTest, OverseerTest]
[junit4] Completed in 71.69s, 9 tests, 1 error <<< FAILURES!
[...truncated 974 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1296: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:920: There were test failures: 398 suites, 1673 tests, 1 error, 42 ignored (21 assumptions)
Total time: 95 minutes 35 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_60-ea-b15 -server -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure