You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/05/01 00:37:04 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_55) - Build #
10200 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10200/
Java: 32bit/jdk1.7.0_55 -client -XX:+UseParallelGC
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([1BF320DFA26F524F:1FFBAF2CB0CABD6E]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
... 47 more
Build Log:
[...truncated 11054 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-1BF320DFA26F524F-001/init-core-data-001
[junit4] 2> 451440 T1484 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 451441 T1484 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 451441 T1484 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 451444 T1484 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 451444 T1484 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 451445 T1485 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 451545 T1484 oasc.ZkTestServer.run start zk server on port:49248
[junit4] 2> 451546 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 451636 T1491 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43fe20 name:ZooKeeperConnection Watcher:127.0.0.1:49248/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 451636 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 451638 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 451640 T1493 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60c080 name:ZooKeeperConnection Watcher:127.0.0.1:49248 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 451641 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 451645 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 451646 T1495 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ea98b name:ZooKeeperConnection Watcher:127.0.0.1:49248 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 451647 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 451648 T1484 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 451651 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 451655 T1484 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 451657 T1484 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 451660 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 451665 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 451667 T1497 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14e7f9c name:ZooKeeperConnection Watcher:127.0.0.1:49248/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 451667 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 451670 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 451674 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 451679 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 451681 T1499 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3098f2 name:ZooKeeperConnection Watcher:127.0.0.1:49248/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 451681 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 451683 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 451687 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 451695 T1484 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49248_solr
[junit4] 2> 451696 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 451699 T1484 oasc.Overseer.start Overseer (id=91678076890644484-127.0.0.1:49248_solr-n_0000000000) starting
[junit4] 2> 451702 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 451708 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 451712 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 451716 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 451722 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 451728 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 451736 T1501 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 451737 T1501 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:49248_solr
[junit4] 2> 451737 T1500 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 451740 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 451741 T1500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 451741 T1500 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 451742 T1500 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 451745 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 451746 T1491 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> 451747 T1497 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> 452238 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 452346 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 452353 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452353 T1484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 452354 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 452359 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 452360 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452361 T1503 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37cecb name:ZooKeeperConnection Watcher:127.0.0.1:49248/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 452361 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 452363 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 452367 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 452372 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 452372 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452375 T1500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 452375 T1500 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 452379 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452380 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 452386 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452391 T1499 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452494 T1491 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> 452494 T1503 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> 452495 T1484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 452502 T1484 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49248 49248
[junit4] 2> 452609 T1485 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49248 49248
[junit4] 2> 452610 T1484 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 452610 T1500 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:49248_solr
[junit4] 2> 452612 T1504 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:306)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 452615 T1484 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 452616 T1484 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 452616 T1505 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 452716 T1484 oasc.ZkTestServer.run start zk server on port:40229
[junit4] 2> 452717 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 452720 T1511 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c5602c name:ZooKeeperConnection Watcher:127.0.0.1:40229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 452720 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 452722 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 452723 T1513 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d62d38 name:ZooKeeperConnection Watcher:127.0.0.1:40229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 452724 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 452724 T1484 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 452727 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 452728 T1515 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8e13a1 name:ZooKeeperConnection Watcher:127.0.0.1:40229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 452728 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 452728 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 452730 T1484 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 452732 T1484 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 452733 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 452735 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 452736 T1517 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e609f name:ZooKeeperConnection Watcher:127.0.0.1:40229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 452736 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 452737 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 452738 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 452741 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 452742 T1519 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35ab0c name:ZooKeeperConnection Watcher:127.0.0.1:40229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 452742 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 452743 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 452745 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 452749 T1484 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:40229_solr
[junit4] 2> 452749 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 452751 T1484 oasc.Overseer.start Overseer (id=91678076967321604-127.0.0.1:40229_solr-n_0000000000) starting
[junit4] 2> 452753 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 452755 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 452756 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 452758 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 452760 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 452763 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 452766 T1521 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 452767 T1521 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:40229_solr
[junit4] 2> 452767 T1520 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 453770 T1519 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 453773 T1520 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 453774 T1520 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 453775 T1520 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 453775 T1520 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 453778 T1519 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 453779 T1517 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> 453779 T1515 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> 454271 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 454285 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 454292 T1519 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 454292 T1484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 454294 T1520 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 454296 T1519 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 454296 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 454299 T1520 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 454300 T1520 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 454302 T1519 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 454406 T1515 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> 454406 T1517 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> 455460 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 455464 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 455466 T1523 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1efeef0 name:ZooKeeperConnection Watcher:127.0.0.1:40229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 455466 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 455466 T1520 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:40229_solr
[junit4] 2> 455467 T1524 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:306)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 455469 T1484 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:40229_solr
[junit4] 2> 455469 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 455471 T1484 oasc.Overseer.start Overseer (id=91678076967321605-127.0.0.1:40229_solr-n_0000000001) starting
[junit4] 2> 455480 T1526 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 455480 T1525 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 455481 T1526 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:40229_solr
[junit4] 2> 455482 T1525 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 455482 T1525 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 455482 T1525 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 455484 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455484 T1515 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> 455484 T1517 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> 455537 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455537 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 455538 T1525 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 455541 T1484 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91678076967321603-node1_core1-n_0000000002
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:127)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 455543 T1525 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:177)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:631)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1066)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:346)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:242)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 455542 T1517 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 455543 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 455550 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455556 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455558 T1517 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 455558 T1525 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 455561 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455562 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455563 T1525 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 455564 T1523 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455667 T1517 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> 455667 T1515 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> 456551 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 457556 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 458560 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 459563 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 460566 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 461571 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 462577 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 463581 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 464583 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 465588 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 466591 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 467594 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 468599 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 469602 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 470605 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 470615 T1484 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40229 40229
[junit4] 2> 470681 T1505 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40229 40229
[junit4] 2> 470683 T1484 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 2> 470684 T1525 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:40229_solr
[junit4] 2> 470686 T1527 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:306)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=1BF320DFA26F524F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=vi_VN -Dtests.timezone=Africa/Juba -Dtests.file.encoding=US-ASCII
[junit4] ERROR 18.1s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] > at __randomizedtesting.SeedInfo.seed([1BF320DFA26F524F:1FFBAF2CB0CABD6E]:0)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
[junit4] > ... 47 more
[junit4] 2> 470711 T1484 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 470713 T1484 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 470714 T1528 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 470814 T1484 oasc.ZkTestServer.run start zk server on port:58216
[junit4] 2> 470815 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 470821 T1534 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1395668 name:ZooKeeperConnection Watcher:127.0.0.1:58216 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 470821 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 470823 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 470824 T1536 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14558c6 name:ZooKeeperConnection Watcher:127.0.0.1:58216 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 470825 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 470825 T1484 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 470828 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 470829 T1538 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61631 name:ZooKeeperConnection Watcher:127.0.0.1:58216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 470829 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 470829 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 470831 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 470832 T1540 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54414d name:ZooKeeperConnection Watcher:127.0.0.1:58216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 470832 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 470833 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 470836 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 470839 T1484 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:58216_solr
[junit4] 2> 470839 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 470841 T1484 oasc.Overseer.start Overseer (id=91678078153457667-127.0.0.1:58216_solr-n_0000000000) starting
[junit4] 2> 470843 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 470845 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 470848 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 470851 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 470854 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 470859 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 470864 T1542 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 470864 T1484 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 470864 T1541 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 470864 T1542 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:58216_solr
[junit4] 2> 470867 T1484 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 470868 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 470872 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 470873 T1544 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cdb2d2 name:ZooKeeperConnection Watcher:127.0.0.1:58216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 470874 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 470875 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 470878 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 470882 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 470883 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 470883 T1541 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> 470883 T1541 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 470884 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 470885 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 470886 T1538 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> 470886 T1544 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> 471382 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 471391 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 471394 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 471395 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 471395 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 471397 T1541 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> 471397 T1541 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 471397 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 471399 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 471501 T1538 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> 471501 T1544 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> 471895 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 471908 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 471915 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 471915 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 471916 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 471918 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 471919 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 471923 T1541 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> 471924 T1541 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 471924 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 471927 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 472030 T1538 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> 472030 T1544 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> 472418 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 472423 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 472429 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 472429 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 472429 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 472430 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 472432 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 472534 T1544 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> 472534 T1538 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> 472581 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 472581 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 472582 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 472583 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 472583 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 472583 T1541 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> 472585 T1541 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> 472586 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 472587 T1541 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> 472587 T1541 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 472587 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 472589 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 472695 T1538 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> 472695 T1544 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> 473083 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
[junit4] 2> 473098 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
[junit4] 2> 473106 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 473106 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 473107 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 473108 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 473108 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 473114 T1541 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> 473114 T1541 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 473115 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 473118 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 473221 T1538 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> 473221 T1544 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> 473608 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 473619 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 473628 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 473628 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 473629 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 473631 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 473631 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 473637 T1541 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> 473637 T1541 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 473638 T1541 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 473641 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 473744 T1544 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> 473744 T1538 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> 474131 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
[junit4] 2> 474140 T1484 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
[junit4] 2> 474147 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 474148 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 474148 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 474150 T1541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 474155 T1540 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 474259 T1538 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> 474259 T1544 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> 474304 T1484 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:58216 58216
[junit4] 2> 474525 T1528 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:58216 58216
[junit4] 2> 474527 T1484 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 474527 T1541 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:58216_solr
[junit4] 2> 474529 T1545 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:306)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 474536 T1484 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignmentBigger
[junit4] 2> 474537 T1484 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 474538 T1546 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 474638 T1484 oasc.ZkTestServer.run start zk server on port:55081
[junit4] 2> 474639 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474643 T1552 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ba6dcc name:ZooKeeperConnection Watcher:127.0.0.1:55081 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474643 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474647 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474654 T1554 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d31a4b name:ZooKeeperConnection Watcher:127.0.0.1:55081 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474654 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474655 T1484 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 474660 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474662 T1556 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14cd55d name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474663 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474663 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 474667 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474668 T1558 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13cb9d2 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474669 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474671 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 474676 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 474682 T1484 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55081_solr
[junit4] 2> 474683 T1484 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 474687 T1484 oasc.Overseer.start Overseer (id=91678078404067331-127.0.0.1:55081_solr-n_0000000000) starting
[junit4] 2> 474691 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 474696 T1484 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 474701 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 474706 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 474711 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 474717 T1484 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 474726 T1560 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 474727 T1484 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 474727 T1560 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:55081_solr
[junit4] 2> 474727 T1559 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 474730 T1484 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 474733 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474737 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474739 T1562 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a4a129 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474740 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474742 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474746 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node0
[junit4] 2> 474751 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474753 T1564 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63f701 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474753 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474755 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474758 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 474763 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474764 T1566 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@db4b61 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474765 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474767 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474769 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 474773 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474775 T1568 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@105427d name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474776 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474777 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474780 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node3
[junit4] 2> 474785 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474787 T1570 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@154545f name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474788 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474790 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474793 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node4
[junit4] 2> 474798 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474799 T1572 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6583ce name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474800 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474802 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474806 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node5
[junit4] 2> 474811 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474812 T1574 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@165d0f4 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474813 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474815 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474819 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node6
[junit4] 2> 474824 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474826 T1576 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26ff91 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474826 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474828 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474832 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node7
[junit4] 2> 474838 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474839 T1578 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@152cff6 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474840 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474842 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474845 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node8
[junit4] 2> 474850 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474852 T1580 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e87340 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474852 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474855 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474859 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node9
[junit4] 2> 474866 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474867 T1582 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f21265 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474868 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474870 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474873 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node10
[junit4] 2> 474880 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474882 T1584 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@30e366 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474882 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474884 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474888 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node11
[junit4] 2> 474894 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474896 T1586 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c43644 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474896 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474898 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474902 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node12
[junit4] 2> 474908 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474910 T1588 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14a3af1 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474910 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474913 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474916 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node13
[junit4] 2> 474923 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474925 T1590 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ee8ed1 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474925 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474927 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474931 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node14
[junit4] 2> 474938 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474940 T1592 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b86a51 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474940 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474942 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474946 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node15
[junit4] 2> 474952 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474954 T1594 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16ecef2 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474954 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474956 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474960 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node16
[junit4] 2> 474968 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474969 T1596 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f75e8e name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474970 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474972 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474975 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node17
[junit4] 2> 474982 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 474984 T1598 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16d9b08 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 474985 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 474986 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 474990 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node18
[junit4] 2> 474998 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 475000 T1600 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f74f88 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 475001 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 475003 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 475006 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node19
[junit4] 2> 475013 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 475015 T1602 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e32b3c name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 475015 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 475017 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 475020 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node20
[junit4] 2> 475027 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 475029 T1604 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@119956 name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 475029 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 475031 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 475034 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node21
[junit4] 2> 475041 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 475043 T1606 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@be9eca name:ZooKeeperConnection Watcher:127.0.0.1:55081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 475044 T1484 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 475045 T1484 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 475048 T1484 oascc.SolrZkClient.makePath makePath: /live_nodes/node22
[junit4] 2> 475055 T1484 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 475056 T1608 oascc.ConnectionManager.process Watcher org.apache
[...truncated too long message...]
ection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 493063 T2031 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 493063 T2031 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 493065 T2030 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 493168 T2024 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> 493214 T1484 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39532 39532
[junit4] 2> 493350 T2018 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39532 39532
[junit4] 2> 493351 T1484 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 493352 T2031 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:39532_solr
[junit4] 2> 493352 T2033 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:306)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 493353 T1484 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 493353 T1484 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 494217 T2016 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 494218 T2016 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 494219 T2016 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 496354 T1484 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-1BF320DFA26F524F-001
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=vi_VN, timezone=Africa/Juba
[junit4] 2> NOTE: Linux 3.8.0-38-generic i386/Oracle Corporation 1.7.0_55 (32-bit)/cpus=8,threads=1,free=170446392,total=298057728
[junit4] 2> NOTE: All tests run in this JVM: [ShardRoutingTest, MoreLikeThisHandlerTest, SimpleFacetsTest, TestRequestStatusCollectionAPI, TestSort, CacheHeaderTest, SliceStateUpdateTest, TestExtendedDismaxParser, ResponseLogComponentTest, TestSearcherReuse, ExternalFileFieldSortTest, TestQueryUtils, EnumFieldTest, TestDocSet, SuggesterFSTTest, TestBadConfig, LoggingHandlerTest, URLClassifyProcessorTest, TestSurroundQueryParser, OverseerCollectionProcessorTest, AnalysisErrorHandlingTest, TestSearchPerf, HdfsWriteToMultipleCollectionsTest, TestRemoteStreaming, TestSolrIndexConfig, TestSolrXml, TestGroupingSearch, CircularListTest, SliceStateTest, TestNRTOpen, TestOverriddenPrefixQueryForCustomFieldType, CoreMergeIndexesAdminHandlerTest, TestRandomDVFaceting, SynonymTokenizerTest, SpatialFilterTest, RecoveryZkTest, DirectUpdateHandlerOptimizeTest, TestFieldTypeResource, TestFunctionQuery, TestCharFilters, TestDocBasedVersionConstraints, DistribDocExpirationUpdateProcessorTest, FieldFacetExtrasTest, FieldMutatingUpdateProcessorTest, TestManagedResource, DocumentBuilderTest, TestRecoveryHdfs, PreAnalyzedFieldTest, TestSimpleQParserPlugin, DistributedQueryComponentCustomSortTest, SearchHandlerTest, SpellingQueryConverterTest, CursorMarkTest, TestNonNRTOpen, FileBasedSpellCheckerTest, TestConfig, BasicDistributedZkTest, TestPseudoReturnFields, OverseerTest]
[junit4] Completed on J0 in 44.96s, 9 tests, 1 error <<< FAILURES!
[...truncated 865 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1296: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:920: There were test failures: 398 suites, 1669 tests, 1 error, 37 ignored (16 assumptions)
Total time: 60 minutes 16 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_55 -client -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure