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/03/20 08:33:13 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_51) - Build #
9853 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9853/
Java: 32bit/jdk1.7.0_51 -client -XX:+UseSerialGC
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([DA708D67FD43D90C:DE780294EFE6362D]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
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:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:744)
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:431)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
... 45 more
Build Log:
[...truncated 10659 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 679334 T2181 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 679334 T2181 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1395300002988
[junit4] 2> 679334 T2181 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 679337 T2181 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 679337 T2181 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 679338 T2182 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 679438 T2181 oasc.ZkTestServer.run start zk server on port:34086
[junit4] 2> 679440 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 679482 T2188 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12c774f name:ZooKeeperConnection Watcher:127.0.0.1:34086 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 679483 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 679488 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 679490 T2190 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18c60a0 name:ZooKeeperConnection Watcher:127.0.0.1:34086 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 679490 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 679491 T2181 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 679496 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 679498 T2192 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10b51ab name:ZooKeeperConnection Watcher:127.0.0.1:34086/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 679498 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 679499 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 679502 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 679504 T2194 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8d8baf name:ZooKeeperConnection Watcher:127.0.0.1:34086/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 679504 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 679506 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 679509 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 679515 T2181 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:34086_solr
[junit4] 2> 679515 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 679518 T2181 oasc.Overseer.start Overseer (id=91442380996149251-127.0.0.1:34086_solr-n_0000000000) starting
[junit4] 2> 679521 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 679526 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 679530 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 679533 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 679535 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 679537 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 679541 T2196 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 679541 T2181 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 679541 T2195 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 679541 T2196 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 679543 T2181 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 679544 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 679546 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 679547 T2198 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e176dd name:ZooKeeperConnection Watcher:127.0.0.1:34086/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 679547 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 679548 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 679549 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 679550 T2192 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 679550 T2198 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 679551 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 679552 T2195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 679552 T2195 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> 679553 T2195 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 679553 T2195 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 679554 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 679555 T2192 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> 679555 T2198 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> 680052 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 680058 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 680062 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 680063 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 680063 T2195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 680065 T2195 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> 680065 T2195 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 680066 T2195 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 680067 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 680169 T2198 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> 680169 T2192 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> 680563 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 680570 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 680573 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 680574 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 680574 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 680575 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 680575 T2195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 680577 T2195 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> 680577 T2195 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 680577 T2195 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 680579 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 680681 T2192 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> 680681 T2198 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> 681075 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 681081 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 681092 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 681093 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 681093 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 681094 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 681094 T2195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 681096 T2195 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> 681096 T2195 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 681097 T2195 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 681098 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 681200 T2198 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> 681200 T2192 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> 681594 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 681604 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 681604 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 681604 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 681606 T2195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 681607 T2195 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> 681607 T2195 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 681608 T2195 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 681612 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 681714 T2198 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> 681714 T2192 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> 682104 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 682109 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 682110 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 682110 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 682111 T2195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 682112 T2195 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> 682112 T2195 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 682112 T2195 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 682114 T2194 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 682249 T2192 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> 682249 T2198 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> 682610 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 682616 T2198 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 682616 T2198 oasc.LeaderElector$1.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:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[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> 682617 T2198 oasc.LeaderElector$1.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:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[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> 682618 T2181 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34086 34086
[junit4] 2> 682618 T2198 oasc.LeaderElector$1.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:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[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> 682698 T2181 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 682703 T2181 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 682703 T2181 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 682704 T2199 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 682804 T2181 oasc.ZkTestServer.run start zk server on port:38049
[junit4] 2> 682805 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 682807 T2205 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a2aa6 name:ZooKeeperConnection Watcher:127.0.0.1:38049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 682807 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 682808 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 682809 T2207 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aeacbf name:ZooKeeperConnection Watcher:127.0.0.1:38049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 682809 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 682840 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 682842 T2209 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a6f311 name:ZooKeeperConnection Watcher:127.0.0.1:38049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 682842 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 682843 T2181 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 682846 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 682850 T2181 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 682853 T2181 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 682855 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 682859 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 682860 T2211 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1898e8b name:ZooKeeperConnection Watcher:127.0.0.1:38049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 682861 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 682862 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 682865 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 682870 T2181 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38049_solr
[junit4] 2> 682870 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 682873 T2181 oasc.Overseer.start Overseer (id=91442381216808963-127.0.0.1:38049_solr-n_0000000000) starting
[junit4] 2> 682876 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 682880 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 682884 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 682889 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 682893 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 682898 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 682904 T2213 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 682905 T2212 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 682905 T2213 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 682907 T2181 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 682908 T2212 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 682908 T2212 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> 682909 T2212 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 682912 T2211 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 682913 T2205 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> 682959 T2181 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 682962 T2211 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 682963 T2212 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 682964 T2212 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> 682964 T2212 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 682964 T2212 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 682966 T2211 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 683068 T2205 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> 683117 T2181 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:38049 38049
[junit4] 2> 683188 T2181 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 683195 T2181 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 683195 T2181 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 683196 T2214 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 683296 T2181 oasc.ZkTestServer.run start zk server on port:34669
[junit4] 2> 683297 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 683300 T2220 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c9ca17 name:ZooKeeperConnection Watcher:127.0.0.1:34669/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 683301 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 683301 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 683302 T2222 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f3b01f name:ZooKeeperConnection Watcher:127.0.0.1:34669 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 683302 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 683318 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 683321 T2224 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b9f18 name:ZooKeeperConnection Watcher:127.0.0.1:34669 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 683321 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 683321 T2181 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 683325 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 683328 T2181 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 683330 T2181 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 683333 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 683336 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 683341 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 683343 T2226 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f597f name:ZooKeeperConnection Watcher:127.0.0.1:34669/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 683343 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 683345 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 683348 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 683352 T2181 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:34669_solr
[junit4] 2> 683352 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 683353 T2181 oasc.Overseer.start Overseer (id=91442381249249283-127.0.0.1:34669_solr-n_0000000000) starting
[junit4] 2> 683354 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 683357 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 683362 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 683365 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 683367 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 683371 T2228 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 683372 T2228 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 683373 T2227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 683374 T2227 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 683374 T2227 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> 683375 T2220 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> 683378 T2227 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> 683380 T2220 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> 683382 T2227 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 683384 T2227 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 683385 T2227 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> 683388 T2226 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 683389 T2220 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> 683477 T2181 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34669 34669
[junit4] 2> 683598 T2181 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 683607 T2181 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 683608 T2181 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 683609 T2229 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 683709 T2181 oasc.ZkTestServer.run start zk server on port:51591
[junit4] 2> 683710 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 683712 T2235 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c4f863 name:ZooKeeperConnection Watcher:127.0.0.1:51591/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 683713 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 683714 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 683715 T2237 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3bf93a name:ZooKeeperConnection Watcher:127.0.0.1:51591 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 683715 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 683734 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 683735 T2239 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1586080 name:ZooKeeperConnection Watcher:127.0.0.1:51591 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 683736 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 683736 T2181 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 683740 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 683744 T2181 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 683747 T2181 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 683749 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 683752 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 683754 T2241 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@634207 name:ZooKeeperConnection Watcher:127.0.0.1:51591/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 683754 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 683755 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 683758 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 683760 T2241 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 683761 T2235 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 683761 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 683762 T2243 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b30494 name:ZooKeeperConnection Watcher:127.0.0.1:51591/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 683763 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 683764 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 683765 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 683769 T2181 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:51591_solr
[junit4] 2> 683769 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 683771 T2181 oasc.Overseer.start Overseer (id=91442381276643332-127.0.0.1:51591_solr-n_0000000000) starting
[junit4] 2> 683773 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 683777 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 683779 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 683781 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 683783 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 683784 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 683790 T2245 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 683792 T2244 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 683792 T2245 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 683794 T2244 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 683795 T2244 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> 683795 T2244 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 683796 T2244 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 683798 T2243 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 683799 T2235 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> 683799 T2241 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> 684293 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 684299 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 684302 T2243 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 684302 T2181 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 684303 T2244 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 684304 T2235 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 684304 T2241 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 684305 T2230 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144de5c7d690000, 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:744)
[junit4] 2>
[junit4] 2> 684306 T2181 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51591 51591
[junit4] 2> 684485 T2181 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 684489 T2181 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 684489 T2181 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 684490 T2246 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 684590 T2181 oasc.ZkTestServer.run start zk server on port:60151
[junit4] 2> 684591 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 684594 T2252 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17fcaf1 name:ZooKeeperConnection Watcher:127.0.0.1:60151 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 684595 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 684612 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 684613 T2254 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1603726 name:ZooKeeperConnection Watcher:127.0.0.1:60151 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 684614 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 684614 T2181 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 684617 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 684618 T2256 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@576619 name:ZooKeeperConnection Watcher:127.0.0.1:60151/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 684618 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 684618 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 684620 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 684621 T2258 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9b0bc6 name:ZooKeeperConnection Watcher:127.0.0.1:60151/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 684621 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 684622 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 684623 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 684625 T2181 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60151_solr
[junit4] 2> 684625 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 684627 T2181 oasc.Overseer.start Overseer (id=91442381334577155-127.0.0.1:60151_solr-n_0000000000) starting
[junit4] 2> 684628 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 684630 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 684631 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 684633 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 684635 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 684636 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 684642 T2260 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 684642 T2181 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 684643 T2260 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 684643 T2259 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 684645 T2181 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 684647 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 684648 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 684649 T2262 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b679a8 name:ZooKeeperConnection Watcher:127.0.0.1:60151/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 684650 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 684651 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 684652 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 684654 T2256 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 684654 T2262 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 684655 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 684656 T2259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 684656 T2259 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> 684656 T2259 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 684657 T2259 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 684658 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 684659 T2256 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> 684659 T2262 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> 685155 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 685164 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 685171 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 685173 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 685173 T2259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 685175 T2259 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> 685176 T2259 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 685176 T2259 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 685178 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 685279 T2262 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> 685279 T2256 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> 685673 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 685678 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 685680 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 685680 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 685681 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 685681 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 685681 T2259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 685683 T2259 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> 685684 T2259 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 685684 T2259 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 685685 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 685862 T2256 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> 685862 T2262 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> 686181 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 686187 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 686190 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686190 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686190 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686191 T2259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 686193 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686295 T2262 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> 686295 T2256 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> 686343 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686343 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686343 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686344 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686344 T2259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 686345 T2259 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":"",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 686347 T2259 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":""}
[junit4] 2> 686350 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686350 T2259 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":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 686350 T2259 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 686351 T2259 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 686353 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686454 T2256 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> 686454 T2262 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> 686845 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
[junit4] 2> 686893 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
[junit4] 2> 686898 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686898 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686898 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686899 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 686899 T2259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 686901 T2259 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":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 686901 T2259 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 686902 T2259 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 686903 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 687005 T2262 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> 687005 T2256 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> 687399 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 687407 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 687411 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 687411 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 687412 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 687413 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 687413 T2259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 687415 T2259 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> 687415 T2259 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 687415 T2259 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 687416 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 687520 T2256 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> 687520 T2262 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> 687913 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
[junit4] 2> 687919 T2181 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
[junit4] 2> 687922 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 687922 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 687922 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 687923 T2259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 687925 T2258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 688079 T2262 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> 688079 T2256 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> 688125 T2262 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 688127 T2181 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60151 60151
[junit4] 2> 688340 T2181 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 688344 T2181 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignmentBigger
[junit4] 2> 688345 T2181 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 688345 T2263 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 688445 T2181 oasc.ZkTestServer.run start zk server on port:49972
[junit4] 2> 688446 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688448 T2269 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10147fa name:ZooKeeperConnection Watcher:127.0.0.1:49972 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688448 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688475 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688476 T2271 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f4251 name:ZooKeeperConnection Watcher:127.0.0.1:49972 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688476 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688476 T2181 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 688478 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688479 T2273 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19fa99f name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688479 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688479 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 688481 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688482 T2275 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b3265a name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688482 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688483 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 688484 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 688486 T2181 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49972_solr
[junit4] 2> 688487 T2181 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 688488 T2181 oasc.Overseer.start Overseer (id=91442381587087363-127.0.0.1:49972_solr-n_0000000000) starting
[junit4] 2> 688489 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 688491 T2181 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 688493 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 688495 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 688497 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 688504 T2181 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 688508 T2277 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 688508 T2181 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 688508 T2277 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 688508 T2276 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 688510 T2181 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 688511 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688512 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688513 T2279 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@103e26a name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688513 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688514 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688515 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node0
[junit4] 2> 688517 T2273 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 688517 T2279 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 688517 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688518 T2281 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@853730 name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688518 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688519 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688520 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 688522 T2279 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 688522 T2281 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 688522 T2273 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 688522 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688523 T2283 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1098304 name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688523 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688524 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688525 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 688527 T2283 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 688527 T2279 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 688527 T2273 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 688527 T2281 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 688528 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688529 T2285 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c4b9b7 name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688529 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688530 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688531 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node3
[junit4] 2> 688533 T2279 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 688533 T2285 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 688533 T2283 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 688533 T2281 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 688533 T2273 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 688534 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688535 T2287 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f8b674 name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688535 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688536 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688537 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node4
[junit4] 2> 688539 T2273 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 688539 T2285 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 688539 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688539 T2283 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 688539 T2279 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 688539 T2281 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 688539 T2287 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 688540 T2289 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cf1694 name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688541 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688541 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688543 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node5
[junit4] 2> 688544 T2281 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 688545 T2279 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 688545 T2289 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 688545 T2273 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 688545 T2283 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 688544 T2287 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 688544 T2285 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 688545 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688546 T2291 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e824f6 name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688546 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688547 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688548 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node6
[junit4] 2> 688551 T2281 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 688551 T2273 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 688551 T2283 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 688552 T2291 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 688551 T2287 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 688552 T2279 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 688552 T2289 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 688552 T2285 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 688552 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688553 T2293 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15f2c7b name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688553 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688554 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688556 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node7
[junit4] 2> 688558 T2273 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 688558 T2283 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 688558 T2293 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 688558 T2285 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 688558 T2291 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 688558 T2287 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 688558 T2279 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 688558 T2289 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 688558 T2281 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 688559 T2295 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@941256 name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688558 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688560 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688561 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688562 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node8
[junit4] 2> 688564 T2279 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 688564 T2283 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 688564 T2285 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 688564 T2295 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 688564 T2281 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 688564 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688564 T2293 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 688564 T2289 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 688564 T2287 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 688564 T2273 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 688565 T2297 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bd431 name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688565 T2291 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 688567 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688568 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688569 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node9
[junit4] 2> 688571 T2273 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 688571 T2287 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 688571 T2291 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 688571 T2297 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 688571 T2283 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 688572 T2285 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 688572 T2279 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 688572 T2289 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 688572 T2281 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 688572 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688573 T2299 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@318468 name:ZooKeeperConnection Watcher:127.0.0.1:49972/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 688572 T2295 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 688572 T2293 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 688573 T2181 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 688575 T2181 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 688576 T2181 oascc.SolrZkClient.makePath makePath: /live_nodes/node10
[junit4] 2> 688578 T2273 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 688578 T2289 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 688579 T2283 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 688578 T2299 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 688578 T2291 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 688579 T2181 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 688578 T2295 oascc.ZkStateReader$3.process Updating l
[...truncated too long message...]
end4LetterWord connecting to 127.0.0.1:53964 53964
[junit4] 2> 724675 T2181 oas.SolrTestCaseJ4.tearDown ###Ending testShardLeaderChange
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 724679 T2181 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 724680 T2181 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 725252 T2613 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 725253 T2613 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 725253 T2613 oasc.LeaderElector$1.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:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[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> 725254 T2613 oasc.LeaderElector$1.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:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[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> 725739 T2621 oasc.LeaderElector$1.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:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[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> 725739 T2621 oasc.LeaderElector$1.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:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[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> 727680 T2181 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=DefaultSimilarity, locale=sr_BA_#Latn, timezone=Asia/Bangkok
[junit4] 2> NOTE: Linux 3.8.0-37-generic i386/Oracle Corporation 1.7.0_51 (32-bit)/cpus=8,threads=1,free=34019912,total=193327104
[junit4] 2> NOTE: All tests run in this JVM: [DocumentBuilderTest, AbstractAnalyticsStatsTest, FastVectorHighlighterTest, TestAddFieldRealTimeGet, TestUniqueKeyFieldResource, TestSuggestSpellingConverter, FieldMutatingUpdateProcessorTest, TestCollapseQParserPlugin, TestSchemaSimilarityResource, TestSolrXml, SolrCoreTest, ShardSplitTest, TestCoreContainer, TestValueSourceCache, SoftAutoCommitTest, TestConfig, UnloadDistributedZkTest, DistributedSpellCheckComponentTest, PolyFieldTest, PeerSyncTest, SchemaVersionSpecificBehaviorTest, HdfsBasicDistributedZkTest, TestSearchPerf, DistributedQueryComponentOptimizationTest, TestManagedResourceStorage, DistributedSuggestComponentTest, TestSolrXmlPersistor, TestLuceneMatchVersion, BadComponentTest, TestSolrXMLSerializer, TestDefaultSearchFieldResource, TestReversedWildcardFilterFactory, SynonymTokenizerTest, OverseerCollectionProcessorTest, SpellPossibilityIteratorTest, DateMathParserTest, TestCharFilters, ResourceLoaderTest, OverseerRolesTest, ZkControllerTest, TestRealTimeGet, TestLFUCache, MBeansHandlerTest, RegexBoostProcessorTest, TestBM25SimilarityFactory, AnalysisAfterCoreReloadTest, TestPostingsSolrHighlighter, UUIDFieldTest, LukeRequestHandlerTest, TestGroupingSearch, SOLR749Test, RemoteQueryErrorTest, QueryEqualityTest, DOMUtilTest, ModifyConfFileTest, TestClassNameShortening, CoreMergeIndexesAdminHandlerTest, SuggesterTest, TermVectorComponentTest, TestLMJelinekMercerSimilarityFactory, TermsComponentTest, BasicFunctionalityTest, TestPHPSerializedResponseWriter, TestPerFieldSimilarity, TestFieldSortValues, TestQueryUtils, TestBlendedInfixSuggestions, ResponseLogComponentTest, CoreAdminHandlerTest, AsyncMigrateRouteKeyTest, TestFileDictionaryLookup, TestCollationFieldDocValues, SearchHandlerTest, TestSchemaVersionResource, AbstractAnalyticsFacetTest, SolrInfoMBeanTest, MoreLikeThisHandlerTest, PrimitiveFieldTypeTest, QueryParsingTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestSolrQueryParser, URLClassifyProcessorTest, DistributedTermsComponentTest, TestRandomDVFaceting, ShowFileRequestHandlerTest, SuggesterFSTTest, CircularListTest, LoggingHandlerTest, QueryElevationComponentTest, ClusterStateTest, OverseerTest]
[junit4] Completed on J0 in 48.38s, 9 tests, 1 error <<< FAILURES!
[...truncated 705 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1275: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:907: There were test failures: 391 suites, 1644 tests, 1 error, 49 ignored (28 assumptions)
Total time: 57 minutes 23 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_51 -client -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure