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/11 14:20:36 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_60-ea-b15) -
Build # 10279 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10279/
Java: 32bit/jdk1.7.0_60-ea-b15 -client -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
createcollection the collection error [Watcher fired on path: null state: SyncConnected type None]
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: createcollection the collection error [Watcher fired on path: null state: SyncConnected type None]
at __randomizedtesting.SeedInfo.seed([C611100F7AC1DEA3:47F79E170D9EBE9F]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:554)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
at org.apache.solr.client.solrj.request.CollectionAdminRequest.process(CollectionAdminRequest.java:300)
at org.apache.solr.client.solrj.request.CollectionAdminRequest.createCollection(CollectionAdminRequest.java:360)
at org.apache.solr.client.solrj.request.CollectionAdminRequest.createCollection(CollectionAdminRequest.java:346)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:298)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:201)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11138 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/init-core-data-001
[junit4] 2> 747292 T3280 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
[junit4] 2> 747293 T3280 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /zjh/
[junit4] 2> 747298 T3280 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 747298 T3280 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 747299 T3281 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 747399 T3280 oasc.ZkTestServer.run start zk server on port:37831
[junit4] 2> 747400 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 753549 T3284 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 6147ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
[junit4] 2> 753551 T3287 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fd7cb1 name:ZooKeeperConnection Watcher:127.0.0.1:37831 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 753551 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 753551 T3280 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 753554 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 753555 T3289 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bc9ab4 name:ZooKeeperConnection Watcher:127.0.0.1:37831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 753556 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 753556 T3280 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 753567 T3280 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 753569 T3280 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 753570 T3280 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 753572 T3280 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 753572 T3280 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 753580 T3280 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 753581 T3280 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 753585 T3280 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 753585 T3280 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 753589 T3280 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 753591 T3280 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 753594 T3280 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 753594 T3280 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 753598 T3280 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 753599 T3280 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 753604 T3280 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 753604 T3280 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 753606 T3280 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 753607 T3280 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 753609 T3280 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 753609 T3280 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 753611 T3280 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 753612 T3280 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 753614 T3280 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 753615 T3280 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 753617 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 753618 T3291 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@126758f name:ZooKeeperConnection Watcher:127.0.0.1:37831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 753618 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> Using new style solr.xml
[junit4] 2> 753923 T3280 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 753925 T3280 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 753926 T3280 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:40582
[junit4] 2> 753928 T3280 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 753928 T3280 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 753929 T3280 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-002
[junit4] 2> 753929 T3280 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-002/'
[junit4] 2> 753942 T3280 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-002/solr.xml
[junit4] 2> 753972 T3280 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-002
[junit4] 2> 753972 T3280 oasc.CoreContainer.<init> New CoreContainer 1870730
[junit4] 2> 753972 T3280 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-002/]
[junit4] 2> 753973 T3280 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 753974 T3280 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 753974 T3280 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 753974 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 753975 T3280 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 753975 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 753975 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 753975 T3280 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 753976 T3280 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 753978 T3280 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 753978 T3280 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 753978 T3280 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 753979 T3280 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:37831/solr
[junit4] 2> 753979 T3280 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 753980 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 753982 T3302 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17042d6 name:ZooKeeperConnection Watcher:127.0.0.1:37831 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 753982 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 753984 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 753985 T3304 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19878b9 name:ZooKeeperConnection Watcher:127.0.0.1:37831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 753985 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 753987 T3280 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 753989 T3280 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 753991 T3280 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 753992 T3280 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 753994 T3280 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 753996 T3280 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 753997 T3280 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40582_zjh
[junit4] 2> 753998 T3280 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40582_zjh
[junit4] 2> 754002 T3280 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 754003 T3280 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 754005 T3280 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:40582_zjh
[junit4] 2> 754006 T3280 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 754007 T3280 oasc.Overseer.start Overseer (id=91737959269072900-127.0.0.1:40582_zjh-n_0000000000) starting
[junit4] 2> 754011 T3280 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 754018 T3306 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 754019 T3280 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 754019 T3306 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:40582_zjh
[junit4] 2> 754020 T3280 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 754021 T3280 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 754023 T3305 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 754025 T3280 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-002
[junit4] 2> 754030 T3280 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-002/conf/
[junit4] 2> 754130 T3280 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 754132 T3280 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 754132 T3280 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 754134 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 754135 T3309 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@146803f name:ZooKeeperConnection Watcher:127.0.0.1:37831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 754135 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 754137 T3280 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 754138 T3280 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 754381 T3280 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 754382 T3280 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 754384 T3280 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 754385 T3280 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:43091
[junit4] 2> 754387 T3280 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 754387 T3280 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 754387 T3280 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003
[junit4] 2> 754388 T3280 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003/'
[junit4] 2> 754401 T3280 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003/solr.xml
[junit4] 2> 754430 T3280 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003
[junit4] 2> 754430 T3280 oasc.CoreContainer.<init> New CoreContainer 15810289
[junit4] 2> 754431 T3280 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003/]
[junit4] 2> 754432 T3280 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 754432 T3280 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 754432 T3280 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 754432 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 754433 T3280 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 754433 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 754433 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 754434 T3280 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 754434 T3280 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 754436 T3280 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 754436 T3280 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 754437 T3280 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 754437 T3280 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:37831/solr
[junit4] 2> 754437 T3280 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 754438 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 754439 T3320 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@121c485 name:ZooKeeperConnection Watcher:127.0.0.1:37831 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 754440 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 754442 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 754442 T3322 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1427c3e name:ZooKeeperConnection Watcher:127.0.0.1:37831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 754443 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 754447 T3280 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 755449 T3280 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43091_zjh
[junit4] 2> 755451 T3280 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43091_zjh
[junit4] 2> 755457 T3280 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003
[junit4] 2> 755463 T3280 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003/conf/
[junit4] 2> 755609 T3280 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 755610 T3280 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 755611 T3280 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 755852 T3280 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 755852 T3280 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 755855 T3280 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 755856 T3280 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:53652
[junit4] 2> 755858 T3280 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 755858 T3280 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 755858 T3280 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004
[junit4] 2> 755859 T3280 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004/'
[junit4] 2> 755874 T3280 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004/solr.xml
[junit4] 2> 755904 T3280 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004
[junit4] 2> 755904 T3280 oasc.CoreContainer.<init> New CoreContainer 14542218
[junit4] 2> 755904 T3280 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004/]
[junit4] 2> 755905 T3280 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 755906 T3280 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 755906 T3280 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 755907 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 755907 T3280 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 755908 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 755908 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 755909 T3280 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 755909 T3280 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 755911 T3280 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 755911 T3280 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 755912 T3280 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 755912 T3280 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:37831/solr
[junit4] 2> 755912 T3280 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 755913 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 755915 T3334 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b0dc15 name:ZooKeeperConnection Watcher:127.0.0.1:37831 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 755915 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 755917 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 755920 T3336 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e59995 name:ZooKeeperConnection Watcher:127.0.0.1:37831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 755920 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 755926 T3280 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 756928 T3280 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53652_zjh
[junit4] 2> 756934 T3280 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53652_zjh
[junit4] 2> 756942 T3280 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004
[junit4] 2> 756953 T3280 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004/conf/
[junit4] 2> 757180 T3280 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 757182 T3280 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 757182 T3280 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 757452 T3280 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 757452 T3280 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 757455 T3280 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 757457 T3280 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:54306
[junit4] 2> 757459 T3280 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 757459 T3280 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 757460 T3280 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-005
[junit4] 2> 757460 T3280 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-005/'
[junit4] 2> 757477 T3280 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-005/solr.xml
[junit4] 2> 757508 T3280 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-005
[junit4] 2> 757509 T3280 oasc.CoreContainer.<init> New CoreContainer 29396227
[junit4] 2> 757509 T3280 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-005/]
[junit4] 2> 757510 T3280 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 757510 T3280 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 757511 T3280 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 757511 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 757511 T3280 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 757512 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 757512 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 757512 T3280 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 757513 T3280 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 757515 T3280 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 757515 T3280 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 757515 T3280 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 757516 T3280 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:37831/solr
[junit4] 2> 757516 T3280 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 757517 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 757518 T3348 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1943e9e name:ZooKeeperConnection Watcher:127.0.0.1:37831 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 757519 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 757521 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 757522 T3350 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@163655 name:ZooKeeperConnection Watcher:127.0.0.1:37831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 757522 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 757528 T3280 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 758531 T3280 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54306_zjh
[junit4] 2> 758532 T3280 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54306_zjh
[junit4] 2> 758538 T3280 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-005
[junit4] 2> 758544 T3280 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-005/conf/
[junit4] 2> 758671 T3280 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 758673 T3280 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 758673 T3280 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 758921 T3280 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 4
[junit4] 2> 758922 T3280 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 758925 T3280 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 758926 T3280 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:43181
[junit4] 2> 758927 T3280 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 758927 T3280 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 758928 T3280 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006
[junit4] 2> 758928 T3280 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006/'
[junit4] 2> 758941 T3280 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006/solr.xml
[junit4] 2> 758970 T3280 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006
[junit4] 2> 758971 T3280 oasc.CoreContainer.<init> New CoreContainer 19065708
[junit4] 2> 758971 T3280 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006/]
[junit4] 2> 758972 T3280 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 758972 T3280 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 758973 T3280 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 758973 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 758973 T3280 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 758974 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 758974 T3280 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 758974 T3280 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 758975 T3280 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 758977 T3280 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 758977 T3280 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 758977 T3280 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 758978 T3280 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:37831/solr
[junit4] 2> 758978 T3280 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 758979 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 758980 T3362 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@872865 name:ZooKeeperConnection Watcher:127.0.0.1:37831 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 758980 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 758982 T3280 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 758983 T3364 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c64317 name:ZooKeeperConnection Watcher:127.0.0.1:37831/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 758983 T3280 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 759001 T3280 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 760004 T3280 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43181_zjh
[junit4] 2> 760006 T3280 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43181_zjh
[junit4] 2> 760013 T3280 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006
[junit4] 2> 760018 T3280 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006/conf/
[junit4] 2> 760119 T3280 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 760120 T3280 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 760121 T3280 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 760230 T3318 oasha.CollectionsHandler.handleCreateAction Creating Collection : wt=javabin&router.name=compositeId&action=CREATE&router.field=myOwnField&name=solrj_collection&numShards=2&version=2&replicationFactor=2&collection.configName=conf1
[junit4] 2> 760231 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 760232 T3306 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.name":"compositeId",
[junit4] 2> "router.field":"myOwnField"}
[junit4] 2> 760232 T3306 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.name":"compositeId",
[junit4] 2> "router.field":"myOwnField"}
[junit4] 2> 760233 T3306 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection
[junit4] 2> 760234 T3306 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 760237 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 760238 T3305 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 760238 T3305 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
[junit4] 2> 760239 T3305 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
[junit4] 2> 760240 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 760241 T3336 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 760241 T3364 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 760241 T3322 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 760241 T3304 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 760241 T3309 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 760241 T3350 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 760337 T3306 oasc.OverseerCollectionProcessor.createCollection Creating SolrCores for new collection, shardNames [shard1, shard2] , replicationFactor : 2
[junit4] 2> 760337 T3306 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:40582_zjh
[junit4] 2> 760339 T3306 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:43181_zjh
[junit4] 2> 760340 T3306 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:43091_zjh
[junit4] 2> 760346 T3306 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:53652_zjh
[junit4] 2> 760520 T3359 oasha.CoreAdminHandler.handleCreateAction core create command wt=javabin&shard=shard1&action=CREATE&qt=/admin/cores&name=solrj_collection_shard1_replica2&numShards=2&collection=solrj_collection&version=2&collection.configName=conf1
[junit4] 2> 760523 T3359 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down collection=solrj_collection
[junit4] 2> 760524 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 760524 T3359 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 760526 T3305 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 760527 T3305 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:43181/zjh",
[junit4] 2> "core":"solrj_collection_shard1_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:43181_zjh",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 760528 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 760535 T3330 oasha.CoreAdminHandler.handleCreateAction core create command wt=javabin&shard=shard2&action=CREATE&qt=/admin/cores&name=solrj_collection_shard2_replica2&numShards=2&collection=solrj_collection&version=2&collection.configName=conf1
[junit4] 2> 760537 T3330 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down collection=solrj_collection
[junit4] 2> 760539 T3330 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 760539 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 760540 T3305 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:53652/zjh",
[junit4] 2> "core":"solrj_collection_shard2_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:53652_zjh",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 760545 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 760602 T3300 oasha.CoreAdminHandler.handleCreateAction core create command wt=javabin&shard=shard1&action=CREATE&qt=/admin/cores&name=solrj_collection_shard1_replica1&numShards=2&collection=solrj_collection&version=2&collection.configName=conf1
[junit4] 2> 760602 T3316 oasha.CoreAdminHandler.handleCreateAction core create command wt=javabin&shard=shard2&action=CREATE&qt=/admin/cores&name=solrj_collection_shard2_replica1&numShards=2&collection=solrj_collection&version=2&collection.configName=conf1
[junit4] 2> 760604 T3300 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down collection=solrj_collection
[junit4] 2> 760605 T3316 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down collection=solrj_collection
[junit4] 2> 760606 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 760606 T3300 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 760606 T3316 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 760607 T3305 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:40582/zjh",
[junit4] 2> "core":"solrj_collection_shard1_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:40582_zjh",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 760609 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 760609 T3305 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:43091/zjh",
[junit4] 2> "core":"solrj_collection_shard2_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:43091_zjh",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 760611 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 760713 T3304 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 760713 T3364 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 760713 T3309 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 760713 T3350 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 760713 T3322 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 760713 T3336 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 761525 T3359 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
[junit4] 2> 761526 T3359 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 761527 T3359 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 761527 T3359 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 761528 T3359 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 761529 T3359 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006/solrj_collection_shard1_replica2/'
[junit4] 2> 761539 T3330 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
[junit4] 2> 761540 T3330 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 761541 T3330 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 761541 T3330 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 761542 T3330 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 761543 T3330 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004/solrj_collection_shard2_replica2/'
[junit4] 2> 761576 T3330 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 761586 T3359 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 761620 T3316 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
[junit4] 2> 761621 T3316 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 761622 T3316 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 761622 T3316 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 761620 T3300 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
[junit4] 2> 761623 T3316 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 761624 T3316 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003/solrj_collection_shard2_replica1/'
[junit4] 2> 761624 T3300 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 761625 T3300 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 761625 T3300 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 761626 T3300 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 761631 T3300 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-002/solrj_collection_shard1_replica1/'
[junit4] 2> 761633 T3330 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 761635 T3330 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 761643 T3330 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
[junit4] 2> 761657 T3359 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 761658 T3359 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 761673 T3359 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
[junit4] 2> 761674 T3316 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 761683 T3300 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 761744 T3316 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 761746 T3316 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 761753 T3300 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 761754 T3300 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 761760 T3316 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
[junit4] 2> 761768 T3300 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
[junit4] 2> 761996 T3330 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 762001 T3330 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 762004 T3330 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 762012 T3330 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 762015 T3330 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 762018 T3330 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 762020 T3330 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 762021 T3330 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 762021 T3330 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 762022 T3330 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 762022 T3330 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 762023 T3330 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using configuration from collection solrj_collection
[junit4] 2> 762023 T3330 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 762023 T3330 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004/solrj_collection_shard2_replica2/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004/solrj_collection_shard2_replica2/data/
[junit4] 2> 762024 T3330 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b14a45
[junit4] 2> 762024 T3330 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004/solrj_collection_shard2_replica2/data
[junit4] 2> 762025 T3330 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004/solrj_collection_shard2_replica2/data/index/
[junit4] 2> 762025 T3330 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 762026 T3330 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-004/solrj_collection_shard2_replica2/data/index
[junit4] 2> 762026 T3330 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=53.5791015625, floorSegmentMB=1.158203125, forceMergeDeletesPctAllowed=2.9366319556428158, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 762027 T3330 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@9d137b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@defab0),segFN=segments_1,generation=1}
[junit4] 2> 762027 T3330 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 762031 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 762031 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 762032 T3330 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 762032 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 762032 T3330 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 762032 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 762033 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 762033 T3330 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 762033 T3330 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 762034 T3330 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 762035 T3330 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 762035 T3330 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 762035 T3330 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 762036 T3330 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 762036 T3330 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 762037 T3330 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 762037 T3330 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 762040 T3330 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 762043 T3330 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 762043 T3330 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 762044 T3330 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=20.5048828125, floorSegmentMB=2.0322265625, forceMergeDeletesPctAllowed=6.767061789379087, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 762044 T3330 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@9d137b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@defab0),segFN=segments_1,generation=1}
[junit4] 2> 762045 T3330 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 762045 T3330 oass.SolrIndexSearcher.<init> Opening Searcher@1cfa31e[solrj_collection_shard2_replica2] main
[junit4] 2> 762045 T3330 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 762046 T3330 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 762047 T3330 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 762047 T3330 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 762047 T3330 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 762048 T3330 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 762048 T3330 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 762048 T3330 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 762049 T3330 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 762049 T3330 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 762052 T3370 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@1cfa31e[solrj_collection_shard2_replica2] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 762054 T3330 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
[junit4] 2> 762054 T3330 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:https://127.0.0.1:53652/zjh collection:solrj_collection shard:shard2
[junit4] 2> 762055 T3330 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
[junit4] 2> 762062 T3330 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 762063 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 762064 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 762064 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 762064 T3330 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=1.2579674E14ms
[junit4] 2> 762065 T3305 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 762067 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 762155 T3359 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 762162 T3359 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 762166 T3359 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 762176 T3359 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 762181 T3359 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 762184 T3316 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 762185 T3304 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 762185 T3322 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 762184 T3309 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 762185 T3364 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 762185 T3336 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 762185 T3350 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 762187 T3359 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 762188 T3359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 762189 T3359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 762189 T3359 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 762190 T3359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 762191 T3359 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 762191 T3359 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using configuration from collection solrj_collection
[junit4] 2> 762192 T3316 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 762192 T3359 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 762193 T3359 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006/solrj_collection_shard1_replica2/, dataDir=./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006/solrj_collection_shard1_replica2/data/
[junit4] 2> 762193 T3359 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b14a45
[junit4] 2> 762194 T3359 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006/solrj_collection_shard1_replica2/data
[junit4] 2> 762195 T3359 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006/solrj_collection_shard1_replica2/data/index/
[junit4] 2> 762195 T3316 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 762195 T3359 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory './solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 762196 T3359 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-006/solrj_collection_shard1_replica2/data/index
[junit4] 2> 762197 T3359 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=53.5791015625, floorSegmentMB=1.158203125, forceMergeDeletesPctAllowed=2.9366319556428158, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 762198 T3359 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@90cca1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1bf2f42),segFN=segments_1,generation=1}
[junit4] 2> 762198 T3359 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 762203 T3359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 762203 T3359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 762204 T3359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 762204 T3359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 762204 T3359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 762205 T3359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 762205 T3359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 762206 T3359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 762206 T3359 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 762206 T3316 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 762207 T3359 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 762207 T3359 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 762208 T3359 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 762208 T3359 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 762209 T3359 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 762223 T3359 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 762224 T3316 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 762224 T3359 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 762225 T3359 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 762227 T3359 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 762228 T3300 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 762228 T3316 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 762229 T3316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 762230 T3316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 762230 T3359 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 762230 T3316 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 762230 T3359 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 762231 T3316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 762232 T3316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 762231 T3359 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=20.5048828125, floorSegmentMB=2.0322265625, forceMergeDeletesPctAllowed=6.767061789379087, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 762232 T3316 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using configuration from collection solrj_collection
[junit4] 2> 762233 T3300 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 762233 T3359 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@90cca1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1bf2f42),segFN=segments_1,generation=1}
[junit4] 2> 762233 T3359 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 762233 T3316 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 762234 T3359 oass.SolrIndexSearcher.<init> Opening Searcher@4b65e6[solrj_collection_shard1_replica2] main
[junit4] 2> 762234 T3316 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003/solrj_collection_shard2_replica1/data/
[junit4] 2> 762234 T3359 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 762235 T3316 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b14a45
[junit4] 2> 762235 T3300 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 762236 T3316 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003/solrj_collection_shard2_replica1/data
[junit4] 2> 762236 T3359 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 762237 T3359 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 762236 T3316 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003/solrj_collection_shard2_replica1/data/index/
[junit4] 2> 762237 T3359 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 762238 T3359 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 762237 T3316 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 762238 T3359 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 762238 T3316 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-003/solrj_collection_shard2_replica1/data/index
[junit4] 2> 762239 T3359 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 762239 T3316 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=53.5791015625, floorSegmentMB=1.158203125, forceMergeDeletesPctAllowed=2.9366319556428158, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 762239 T3359 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 762240 T3359 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 762240 T3316 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@b54bfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d7299c),segFN=segments_1,generation=1}
[junit4] 2> 762241 T3316 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 762240 T3359 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 762245 T3372 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica2] Registered new searcher Searcher@4b65e6[solrj_collection_shard1_replica2] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 762245 T3300 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 762246 T3316 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 762247 T3316 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 762247 T3316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 762248 T3316 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 762248 T3359 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica2
[junit4] 2> 762248 T3359 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica2 address:https://127.0.0.1:43181/zjh collection:solrj_collection shard:shard1
[junit4] 2> 762248 T3300 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 762250 T3359 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
[junit4] 2> 762251 T3316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 762251 T3316 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 762252 T3316 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 762253 T3316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 762253 T3316 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 762253 T3300 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 762254 T3316 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 762255 T3300 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 762255 T3300 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 762255 T3316 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 762256 T3316 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 762256 T3300 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 762257 T3316 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 762258 T3300 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 762258 T3300 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 762258 T3316 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 762259 T3300 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using configuration from collection solrj_collection
[junit4] 2> 762258 T3359 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 762259 T3300 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 762259 T3316 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 762260 T3300 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-002/solrj_collection_shard1_replica1/, dataDir=./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001/tempDir-002/solrj_collection_shard1_replica1/data/
[junit4] 2> 762261 T3316 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 762261 T3300 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b14a45
[junit4] 2> 762261 T3304 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChang
[...truncated too long message...]
787231 T3280 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/J1/./solr.cloud.CollectionsAPIDistributedZkTest-C611100F7AC1DEA3-001
[junit4] 2> 39944 T3279 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 10 leaked thread(s).
[junit4] 2> 788008 T3304 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 788011 T3400 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> 788124 T3403 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> 788124 T3322 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 788233 T3406 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> 788233 T3336 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 788327 T3409 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> 788327 T3350 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 788431 T3364 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=ar_EG, timezone=Australia/North
[junit4] 2> NOTE: Linux 3.8.0-39-generic i386/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=8,threads=1,free=233695680,total=455090176
[junit4] 2> NOTE: All tests run in this JVM: [TestExceedMaxTermLength, TestLMDirichletSimilarityFactory, TestAtomicUpdateErrorCases, TestStressLucene, TestFoldingMultitermQuery, TestManagedStopFilterFactory, TestCoreDiscovery, TestIBSimilarityFactory, OutputWriterTest, OverseerRolesTest, TestDistribDocBasedVersion, TestRTGBase, SpellCheckCollatorTest, HdfsRecoveryZkTest, TestComponentsName, CursorPagingTest, ZkSolrClientTest, SolrIndexConfigTest, TestInfoStreamLogging, TestMiniSolrCloudCluster, EnumFieldTest, SuggesterWFSTTest, SolrCoreCheckLockOnStartupTest, TestDFRSimilarityFactory, DistributedDebugComponentTest, BJQParserTest, TestFastWriter, DistributedExpandComponentTest, TestDefaultSearchFieldResource, XsltUpdateRequestHandlerTest, TestFieldCollectionResource, TestLRUCache, DistribCursorPagingTest, TestOmitPositions, TestRandomMergePolicy, DirectSolrConnectionTest, DistanceFunctionTest, TestSolr4Spatial, TestPhraseSuggestions, FileUtilsTest, TestStressRecovery, SolrPluginUtilsTest, TestSolrJ, RangeFacetTest, TestSolrXMLSerializer, StandardRequestHandlerTest, TermVectorComponentDistributedTest, CurrencyFieldOpenExchangeTest, TestCollationField, TestXIncludeConfig, TestSerializedLuceneMatchVersion, TestCodecSupport, TestCursorMarkWithoutUniqueKey, ZkNodePropsTest, TestFieldResource, PrimUtilsTest, CoreAdminRequestStatusTest, TestHashPartitioner, DocumentAnalysisRequestHandlerTest, TestRangeQuery, TestSweetSpotSimilarityFactory, TestQueryTypes, DirectUpdateHandlerTest, TestUpdate, MinimalSchemaTest, HighlighterConfigTest, AddSchemaFieldsUpdateProcessorFactoryTest, StressHdfsTest, AbstractAnalyticsStatsTest, RemoteQueryErrorTest, CollectionsAPIAsyncDistributedZkTest, BasicDistributedZk2Test, TestZkChroot, DocValuesMultiTest, DistributedQueryComponentOptimizationTest, TestReload, ModifyConfFileTest, TestBinaryResponseWriter, PingRequestHandlerTest, TestPartialUpdateDeduplication, MigrateRouteKeyTest, JSONWriterTest, HdfsUnloadDistributedZkTest, FullSolrCloudDistribCmdsTest, LeaderElectionIntegrationTest, DefaultValueUpdateProcessorTest, TestMultiCoreConfBootstrap, TestSimpleQParserPlugin, TestDynamicFieldCollectionResource, TestSolrQueryParserDefaultOperatorResource, HdfsBasicDistributedZk2Test, OpenExchangeRatesOrgProviderTest, TestCSVLoader, DeleteReplicaTest, HdfsChaosMonkeySafeLeaderTest, InfoHandlerTest, TestCollationFieldDocValues, BasicDistributedZkTest, CollectionsAPIDistributedZkTest]
[junit4] Completed on J1 in 41.25s, 1 test, 1 error <<< FAILURES!
[...truncated 605 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: 400 suites, 1679 tests, 1 error, 37 ignored (16 assumptions)
Total time: 61 minutes 9 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_60-ea-b15 -client -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0_20-ea-b11) -
Build # 10280 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10280/
Java: 64bit/jdk1.8.0_20-ea-b11 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
Stack Trace:
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
at __randomizedtesting.SeedInfo.seed([329CEF737853B966:369460806AF65647]:0)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
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:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 10601 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-329CEF737853B966-001/init-core-data-001
[junit4] 2> 1600 T16 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 1600 T16 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1601 T16 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1610 T16 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 1614 T16 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1623 T17 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1717 T16 oasc.ZkTestServer.run start zk server on port:43664
[junit4] 2> 1790 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1871 T18 oazs.NIOServerCnxn.doIO WARN Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
[junit4] 2> 3453 T22 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@559e868b name:ZooKeeperConnection Watcher:127.0.0.1:43664/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3454 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3456 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3460 T25 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43c11099 name:ZooKeeperConnection Watcher:127.0.0.1:43664 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3460 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3474 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3481 T27 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23bb0d79 name:ZooKeeperConnection Watcher:127.0.0.1:43664 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3481 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3483 T16 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 3493 T16 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 3577 T16 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 3581 T16 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 3584 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 3601 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3603 T29 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cfa857e name:ZooKeeperConnection Watcher:127.0.0.1:43664/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3604 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3640 T16 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 3644 T16 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 3657 T16 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:43664_solr
[junit4] 2> 3657 T16 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 3663 T16 oasc.Overseer.start Overseer (id=91738715168702467-127.0.0.1:43664_solr-n_0000000000) starting
[junit4] 2> 3673 T16 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 3678 T16 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 3685 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 3691 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 3700 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 3729 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 3737 T31 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 3740 T31 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:43664_solr
[junit4] 2> 3758 T30 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 3761 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3770 T30 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3772 T30 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 3774 T30 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 3785 T29 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3791 T22 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> 3818 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3821 T29 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3823 T30 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3825 T30 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 3825 T30 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 3825 T30 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 3830 T29 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3933 T22 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> 3976 T16 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:43664 43664
[junit4] 2> 4167 T17 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:43664 43664
[junit4] 2> 4169 T16 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 4170 T30 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:43664_solr
[junit4] 2> 4174 T32 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> 4182 T16 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 4183 T16 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 4184 T33 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 4284 T16 oasc.ZkTestServer.run start zk server on port:58612
[junit4] 2> 4285 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 4290 T39 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61dc3aeb name:ZooKeeperConnection Watcher:127.0.0.1:58612/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 4291 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 4291 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 4293 T41 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58aa41df name:ZooKeeperConnection Watcher:127.0.0.1:58612 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 4294 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 4296 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 4302 T43 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e6e0cbc name:ZooKeeperConnection Watcher:127.0.0.1:58612 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 4302 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 4303 T16 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 4307 T16 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 4312 T16 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 4314 T16 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 4316 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 4320 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 4322 T45 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37c628fc name:ZooKeeperConnection Watcher:127.0.0.1:58612/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 4322 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 4324 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 4326 T16 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 4329 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 4331 T47 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@374d578d name:ZooKeeperConnection Watcher:127.0.0.1:58612/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 4331 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 4332 T16 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 4335 T16 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 4340 T16 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:58612_solr
[junit4] 2> 4341 T16 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 4344 T16 oasc.Overseer.start Overseer (id=91738715329855492-127.0.0.1:58612_solr-n_0000000000) starting
[junit4] 2> 4346 T16 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 4350 T16 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 4358 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 4361 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 4366 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 4372 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 4378 T49 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 4380 T49 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:58612_solr
[junit4] 2> 4381 T48 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 4392 T48 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 4400 T48 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> 4401 T48 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 4403 T48 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 4407 T47 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 4408 T45 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> 4409 T39 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> 4891 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 4910 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 4917 T47 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 4919 T48 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 4921 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 4925 T47 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 4930 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 4933 T51 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3de34c02 name:ZooKeeperConnection Watcher:127.0.0.1:58612/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 4934 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 4935 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 4946 T16 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 4958 T47 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 4958 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 4960 T48 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> 4960 T48 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 4964 T47 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 4968 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 4975 T47 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 4990 T47 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 5094 T51 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> 5095 T39 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> 5098 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 5120 T16 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:58612 58612
[junit4] 2> 5448 T33 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:58612 58612
[junit4] 2> 5451 T16 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 5452 T48 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:58612_solr
[junit4] 2> 5453 T52 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> 5469 T16 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 5470 T16 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 5474 T53 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 5573 T16 oasc.ZkTestServer.run start zk server on port:39664
[junit4] 2> 5575 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 5580 T59 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48ed3ba8 name:ZooKeeperConnection Watcher:127.0.0.1:39664 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5581 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 5584 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 5589 T61 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f49edeb name:ZooKeeperConnection Watcher:127.0.0.1:39664 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5590 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 5590 T16 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 5596 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 5598 T63 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49ce1d30 name:ZooKeeperConnection Watcher:127.0.0.1:39664/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5599 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 5599 T16 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 5606 T16 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 5609 T16 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 5611 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 5614 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 5617 T65 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53289fdc name:ZooKeeperConnection Watcher:127.0.0.1:39664/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5617 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 5631 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 5636 T16 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 5666 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 5674 T67 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7239ce6a name:ZooKeeperConnection Watcher:127.0.0.1:39664/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 5675 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 5678 T16 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 5685 T16 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 5708 T16 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:39664_solr
[junit4] 2> 5709 T16 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 5713 T16 oasc.Overseer.start Overseer (id=91738715414462468-127.0.0.1:39664_solr-n_0000000000) starting
[junit4] 2> 5719 T16 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 5723 T16 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 5728 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 5737 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 5741 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 5747 T16 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 5754 T69 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 5755 T69 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:39664_solr
[junit4] 2> 5756 T68 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 6759 T67 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 6761 T68 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 6762 T68 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> 6762 T68 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 6763 T68 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 6767 T67 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 6768 T63 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> 6769 T65 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> 7259 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 7279 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 7289 T67 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 7291 T68 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 7291 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 7294 T67 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 7298 T67 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 7299 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 7300 T68 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> 7301 T68 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 7313 T67 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 7417 T63 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> 7417 T65 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> 8474 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 8481 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 8493 T71 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@523f4373 name:ZooKeeperConnection Watcher:127.0.0.1:39664/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 8496 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 8497 T68 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:39664_solr
[junit4] 2> 8502 T72 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> 8506 T16 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:39664_solr
[junit4] 2> 8507 T16 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 8510 T16 oasc.Overseer.start Overseer (id=91738715414462469-127.0.0.1:39664_solr-n_0000000001) starting
[junit4] 2> 8519 T73 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 8521 T73 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 8524 T73 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> 8525 T73 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 8526 T74 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 8528 T74 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:39664_solr
[junit4] 2> 8530 T71 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 8531 T65 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> 8539 T63 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> 8593 T71 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 8593 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 8595 T73 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 8607 T65 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 8610 T65 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[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> Caused by: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leaders
[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.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
[junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
[junit4] 2> ... 6 more
[junit4] 2>
[junit4] 2> 8613 T65 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
[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.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> 8615 T71 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 8622 T16 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91738715414462467-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:62)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:483)
[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> 8636 T16 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39664 39664
[junit4] 2> 8718 T73 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
[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.DistributedQueue.orderedChildren(DistributedQueue.java:96)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:455)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:261)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 8941 T73 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:39664_solr
[junit4] 2> 8943 T53 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:39664 39664
[junit4] 2> 8944 T75 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> 8945 T16 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=329CEF737853B966 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=de_CH -Dtests.timezone=Africa/Kigali -Dtests.file.encoding=UTF-8
[junit4] ERROR 3.51s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
[junit4] > at __randomizedtesting.SeedInfo.seed([329CEF737853B966:369460806AF65647]:0)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[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] 2> 8976 T16 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 8978 T16 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 8985 T76 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 9084 T16 oasc.ZkTestServer.run start zk server on port:56635
[junit4] 2> 9085 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 9089 T82 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55a7556e name:ZooKeeperConnection Watcher:127.0.0.1:56635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 9091 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 9092 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 9094 T84 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2606a40a name:ZooKeeperConnection Watcher:127.0.0.1:56635 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 9095 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 9099 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 9104 T86 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@175ccb24 name:ZooKeeperConnection Watcher:127.0.0.1:56635 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 9105 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 9105 T16 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 9108 T16 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 9113 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 9121 T87 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 9124 T91 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c4c188f name:ZooKeeperConnection Watcher:127.0.0.1:56635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 9125 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 9125 T90 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@531c59fb name:ZooKeeperConnection Watcher:127.0.0.1:56635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 9126 T87 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 9128 T16 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 9130 T87 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 9131 T16 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 9133 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 9136 T16 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 9136 T87 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 9140 T16 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 9141 T87 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56635_solr
[junit4] 2> 9142 T87 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 9146 T87 oasc.Overseer.start Overseer (id=91738715644624900-127.0.0.1:56635_solr-n_0000000000) starting
[junit4] 2> 9149 T87 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 9153 T87 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 9156 T87 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 9159 T87 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 9162 T87 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 9167 T87 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 9167 T93 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 9167 T92 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 9170 T87 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 9172 T95 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ddbade8 name:ZooKeeperConnection Watcher:127.0.0.1:56635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 9172 T87 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 9173 T92 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=91738715644624900-127.0.0.1:56635_solr-n_0000000000) am no longer a leader.
[junit4] 2> 9173 T93 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91738715644624900-127.0.0.1:56635_solr-n_0000000000) am no longer a leader.
[junit4] 2> 9173 T92 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:56635_solr
[junit4] 2> 9174 T93 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:56635_solr
[junit4] 2> 9175 T96 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> 9175 T93 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:293)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:206)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 9181 T87 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56635_solr
[junit4] 2> 9182 T87 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 9184 T87 oasc.Overseer.start Overseer (id=91738715644624901-127.0.0.1:56635_solr-n_0000000001) starting
[junit4] 2> 9192 T98 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 9193 T97 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 9193 T98 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:56635_solr
[junit4] 2> 9196 T97 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 9199 T97 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 9200 T97 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 9200 T97 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 9204 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 9206 T91 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> 9646 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 9661 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 9666 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 9668 T97 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 9668 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 9668 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 9673 T97 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 9673 T97 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 9676 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 9677 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 9682 T100 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@232f284d name:ZooKeeperConnection Watcher:127.0.0.1:56635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 9683 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 9685 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 9687 T16 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 9753 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 9753 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 9754 T97 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 9754 T97 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 9767 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 9775 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 9870 T91 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 9870 T100 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 9977 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 9980 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 9981 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 9981 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 9983 T97 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 9984 T97 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 9984 T97 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 9985 T97 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 9989 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 10094 T100 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 10094 T91 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 10481 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 10491 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 10493 T100 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 10543 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 10543 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 10543 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 10544 T97 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 10548 T95 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 10650 T100 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> 10694 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 10695 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 10696 T87 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 10699 T102 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@301aeed6 name:ZooKeeperConnection Watcher:127.0.0.1:56635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 10702 T87 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 10704 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 10706 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 10710 T16 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 10710 T104 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59e4328b name:ZooKeeperConnection Watcher:127.0.0.1:56635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 10711 T87 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 10711 T97 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:56635_solr
[junit4] 2> 10721 T105 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> 10733 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 10732 T87 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56635_solr
[junit4] 2> 10735 T87 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 10737 T87 oasc.Overseer.start Overseer (id=91738715644624904-127.0.0.1:56635_solr-n_0000000002) starting
[junit4] 2> 10757 T107 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 10772 T77 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145ebe036260006, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 10772 T107 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:56635_solr
[junit4] 2> 10774 T106 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 10774 T102 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 10776 T104 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 10776 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 10777 T106 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 10778 T106 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 10778 T106 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 10783 T102 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> 10786 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 10791 T109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@41ee161a name:ZooKeeperConnection Watcher:127.0.0.1:56635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 10791 T106 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 10792 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 10793 T106 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 10793 T106 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 10801 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 10803 T104 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 10806 T16 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 10806 T104 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 10811 T104 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 10811 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 10813 T106 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 10813 T106 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 10817 T104 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 10826 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 10920 T109 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 10921 T102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 11028 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 11035 T104 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 11035 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 11035 T104 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 11036 T104 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 11036 T106 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 11037 T106 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 11037 T106 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 11040 T104 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 11051 T102 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> 11052 T102 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> 11053 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 11084 T109 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 11096 T104 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 11100 T104 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 11202 T109 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> 11255 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 11264 T87 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 11288 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 11300 T111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6dcaf6c8 name:ZooKeeperConnection Watcher:127.0.0.1:56635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 11300 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 11310 T87 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 11311 T113 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ce6a7d3 name:ZooKeeperConnection Watcher:127.0.0.1:56635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 11312 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 11312 T87 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 11314 T106 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:56635_solr
[junit4] 2> 11346 T114 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> 11349 T16 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 11352 T87 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56635_solr
[junit4] 2> 11353 T87 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 11354 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 11361 T87 oasc.Overseer.start Overseer (id=91738715644624907-127.0.0.1:56635_solr-n_0000000003) starting
[junit4] 2> 11377 T111 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 11378 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 11428 T16 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 11437 T118 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 11439 T117 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@377dc67c name:ZooKeeperConnection Watcher:127.0.0.1:56635/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 11439 T118 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:56635_solr
[junit4] 2> 11439 T115 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 11439 T16 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 11442 T16 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 11451 T16 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 11465 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 11467 T113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 11467 T16 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 11467 T115 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 11468 T115 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 11475 T117 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 11475 T111 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 11476 T16 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 11486 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 11488 T115 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 11488 T115 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 11493 T113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 11501 T113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildr
[...truncated too long message...]
WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 30220 T16 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
[junit4] 2> 30226 T16 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
[junit4] 2> 30229 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 30229 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 30229 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 30230 T498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 30231 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 30233 T498 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> 30233 T498 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 30234 T498 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 30235 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 30340 T495 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> 30340 T501 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> 30731 T16 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 30738 T16 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 30741 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 30741 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 30741 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 30744 T498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 30747 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 30749 T498 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> 30749 T498 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 30749 T498 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 30751 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 30853 T495 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> 30853 T501 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> 31248 T16 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
[junit4] 2> 31252 T16 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
[junit4] 2> 31259 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 31259 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 31259 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 31260 T498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 31265 T497 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 31368 T495 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> 31368 T501 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> 31413 T16 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:35630 35630
[junit4] 2> 31727 T485 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:35630 35630
[junit4] 2> 31729 T16 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 31730 T498 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:35630_solr
[junit4] 2> 31730 T502 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> 31732 T16 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 31732 T16 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 34732 T16 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-329CEF737853B966-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene46), sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=de_CH, timezone=Africa/Kigali
[junit4] 2> NOTE: Linux 3.8.0-39-generic amd64/Oracle Corporation 1.8.0_20-ea (64-bit)/cpus=8,threads=1,free=28608936,total=133169152
[junit4] 2> NOTE: All tests run in this JVM: [ShardSplitTest, SliceStateTest, OverseerTest]
[junit4] Completed on J0 in 33.29s, 9 tests, 1 error <<< FAILURES!
[...truncated 1193 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: 400 suites, 1679 tests, 1 error, 37 ignored (16 assumptions)
Total time: 59 minutes 50 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0_20-ea-b11 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure