Build: https://builds.apache.org/job/Lucene-Solr-Tests-5.x-Java7/2119/
1 tests failed. REGRESSION: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch Error Message: There were too many update fails - we expect it can happen, but shouldn't easily Stack Trace: java.lang.AssertionError: There were too many update fails - we expect it can happen, but shouldn't easily at __randomizedtesting.SeedInfo.seed([F1EDE8D81D56886D:700B66C06A09E851]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.assertTrue(Assert.java:43) at org.junit.Assert.assertFalse(Assert.java:68) at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:223) at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) 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.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:365) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) 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:365) at java.lang.Thread.run(Thread.java:745) Build Log: [...truncated 11202 lines...] [junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest [junit4] 2> Creating dataDir: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/init-core-data-001 [junit4] 2> 824233 T2099 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /mvdt/ [junit4] 2> 824242 T2099 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch [junit4] 2> 824243 T2099 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 824244 T2100 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 824344 T2099 oasc.ZkTestServer.run start zk server on port:31502 [junit4] 2> 824345 T2099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 824346 T2099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 824350 T2106 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@588e78a1 name:ZooKeeperConnection Watcher:127.0.0.1:31502 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 824350 T2099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 824350 T2099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 824351 T2099 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 824353 T2099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 824354 T2099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 824356 T2108 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d416932 name:ZooKeeperConnection Watcher:127.0.0.1:31502/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 824356 T2099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 824356 T2099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 824357 T2099 oascc.SolrZkClient.makePath makePath: /collections/collection1 [junit4] 2> 824358 T2099 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards [junit4] 2> 824360 T2099 oascc.SolrZkClient.makePath makePath: /collections/control_collection [junit4] 2> 824361 T2099 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards [junit4] 2> 824363 T2099 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 824364 T2099 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml [junit4] 2> 824366 T2099 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml [junit4] 2> 824367 T2099 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml [junit4] 2> 824470 T2099 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 824471 T2099 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 824475 T2099 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 824476 T2099 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt [junit4] 2> 824480 T2099 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 824481 T2099 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt [junit4] 2> 824485 T2099 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 824486 T2099 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml [junit4] 2> 824490 T2099 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 824491 T2099 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml [junit4] 2> 824495 T2099 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 824496 T2099 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json [junit4] 2> 824500 T2099 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 824501 T2099 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 824505 T2099 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 824506 T2099 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt [junit4] 2> 824510 T2099 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 824511 T2099 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt [junit4] 2> 827323 T2099 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 827330 T2099 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:31505 [junit4] 2> 827331 T2099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 827332 T2099 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 827332 T2099 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-002 [junit4] 2> 827333 T2099 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-002/' [junit4] 2> 827435 T2099 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-002/solr.xml [junit4] 2> 827587 T2099 oasc.CoreContainer.<init> New CoreContainer 1253585526 [junit4] 2> 827588 T2099 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-002/] [junit4] 2> 827589 T2099 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 827589 T2099 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 827590 T2099 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 827590 T2099 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 827590 T2099 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 827591 T2099 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 827591 T2099 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 827591 T2099 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 827592 T2099 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 827592 T2099 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 827593 T2099 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 827593 T2099 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 827594 T2099 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 827594 T2099 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:31502/solr [junit4] 2> 827594 T2099 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 827595 T2099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 827596 T2099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 827598 T2119 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f9074d name:ZooKeeperConnection Watcher:127.0.0.1:31502 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 827598 T2099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 827599 T2099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 827601 T2099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 827602 T2121 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4da002eb name:ZooKeeperConnection Watcher:127.0.0.1:31502/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 827603 T2099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 827604 T2099 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 827607 T2099 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 827609 T2099 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 827611 T2099 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 827614 T2099 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 827616 T2099 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 827617 T2099 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:31505_mvdt [junit4] 2> 827618 T2099 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:31505_mvdt [junit4] 2> 827620 T2099 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 827621 T2099 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 827623 T2099 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 827624 T2099 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:31505_mvdt [junit4] 2> 827625 T2099 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 827627 T2099 oasc.Overseer.start Overseer (id=92479026354192387-127.0.0.1:31505_mvdt-n_0000000000) starting [junit4] 2> 827629 T2099 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 827635 T2099 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 827636 T2123 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 827637 T2099 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 827639 T2099 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 827641 T2099 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 827644 T2122 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 827649 T2125 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection [junit4] 2> 827650 T2125 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 827651 T2125 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 827651 T2126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 827655 T2122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:31505/mvdt", [junit4] 2> "roles":null, [junit4] 2> "collection":"control_collection", [junit4] 2> "shard":null, [junit4] 2> "state":"down", [junit4] 2> "node_name":"127.0.0.1:31505_mvdt", [junit4] 2> "operation":"state", [junit4] 2> "numShards":"1"} [junit4] 2> 827655 T2122 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1] [junit4] 2> 827656 T2122 oasc.Overseer$ClusterStateUpdater.createCollection state version control_collection 1 [junit4] 2> 827656 T2122 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 827660 T2126 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> 828652 T2125 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 828653 T2125 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection [junit4] 2> 828653 T2125 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 828654 T2125 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 828654 T2125 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 828654 T2125 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-002/collection1/' [junit4] 2> 828656 T2125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-002/collection1/lib/.svn/' to classloader [junit4] 2> 828657 T2125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-002/collection1/lib/README' to classloader [junit4] 2> 828657 T2125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-002/collection1/lib/classes/' to classloader [junit4] 2> 828717 T2125 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0 [junit4] 2> 828761 T2125 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 828884 T2125 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 828894 T2125 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 829232 T2125 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 829234 T2125 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 829236 T2125 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 829240 T2125 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 829258 T2125 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 829258 T2125 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory [junit4] 2> 829258 T2125 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-002/collection1/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/control/data/ [junit4] 2> 829259 T2125 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@697c1b7e [junit4] 2> 829262 T2125 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/control/data [junit4] 2> 829262 T2125 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/control/data/index/ [junit4] 2> 829263 T2125 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/control/data/index' doesn't exist. Creating new index... [junit4] 2> 829264 T2125 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/control/data/index [junit4] 2> 829264 T2125 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=50.662109375, floorSegmentMB=0.794921875, forceMergeDeletesPctAllowed=9.61346083338408, segmentsPerTier=30.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.11871855456068783 [junit4] 2> 829269 T2125 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/control/data/index,segFN=segments_1,generation=1} [junit4] 2> 829269 T2125 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 829274 T2125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 829274 T2125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 829275 T2125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 829275 T2125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 829275 T2125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 829275 T2125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 829276 T2125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 829276 T2125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 829276 T2125 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 829277 T2125 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 829277 T2125 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 829278 T2125 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 829278 T2125 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 829279 T2125 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 829279 T2125 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 829279 T2125 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 829280 T2125 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 829280 T2125 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 829281 T2125 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 829281 T2125 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 829298 T2125 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 829300 T2125 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 829302 T2125 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 829304 T2125 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 829307 T2125 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 829307 T2125 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 829308 T2125 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.49973849721668306] [junit4] 2> 829310 T2125 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/control/data/index,segFN=segments_1,generation=1} [junit4] 2> 829310 T2125 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 829311 T2125 oass.SolrIndexSearcher.<init> Opening Searcher@6a75d270[collection1] main [junit4] 2> 829311 T2125 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 829312 T2125 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 829312 T2125 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 829312 T2125 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 829313 T2125 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 829313 T2125 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 829313 T2125 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json [junit4] 2> 829314 T2125 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 829314 T2125 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json [junit4] 2> 829315 T2125 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json [junit4] 2> 829316 T2125 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 829316 T2125 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 829319 T2127 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6a75d270[collection1] main{UninvertingDirectoryReader()} [junit4] 2> 829322 T2125 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 829323 T2130 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:31505/mvdt collection:control_collection shard:shard1 [junit4] 2> 829323 T2099 oass.SolrDispatchFilter.init user.dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1 [junit4] 2> 829323 T2099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 829323 T2130 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election [junit4] 2> 829324 T2099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 829324 T2099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 829325 T2132 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7bfd3403 name:ZooKeeperConnection Watcher:127.0.0.1:31502/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 829326 T2099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 829326 T2099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 829327 T2099 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 829327 T2130 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 829328 T2126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 829328 T2130 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 829329 T2130 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C217 name=collection1 org.apache.solr.core.SolrCore@319f5a8e url=http://127.0.0.1:31505/mvdt/collection1 node=127.0.0.1:31505_mvdt C217_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:31505/mvdt, state=down, node_name=127.0.0.1:31505_mvdt} [junit4] 2> 829329 T2130 C217 P31505 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:31505/mvdt/collection1/ [junit4] 2> 829329 T2099 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 829329 T2130 C217 P31505 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 829329 T2130 C217 P31505 oasc.SyncStrategy.syncToMe http://127.0.0.1:31505/mvdt/collection1/ has no replicas [junit4] 2> 829329 T2130 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:31505/mvdt/collection1/ shard1 [junit4] 2> 829330 T2130 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1 [junit4] 2> 829332 T2126 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> 829332 T2133 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> 829337 T2126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 829337 T2126 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> 829337 T2133 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> 829383 T2130 oasc.ZkController.register We are http://127.0.0.1:31505/mvdt/collection1/ and leader is http://127.0.0.1:31505/mvdt/collection1/ [junit4] 2> 829384 T2130 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:31505/mvdt [junit4] 2> 829384 T2130 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 829384 T2130 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection [junit4] 2> 829384 T2130 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 829386 T2126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 829388 T2122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "base_url":"http://127.0.0.1:31505/mvdt", [junit4] 2> "roles":null, [junit4] 2> "collection":"control_collection", [junit4] 2> "shard":"shard1", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1:31505_mvdt", [junit4] 2> "operation":"state", [junit4] 2> "numShards":"1"} [junit4] 2> 829491 T2126 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> 829491 T2133 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> 830352 T2099 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 [junit4] 2> 830352 T2099 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 830355 T2099 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:31516 [junit4] 2> 830356 T2099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 830356 T2099 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 830356 T2099 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-003 [junit4] 2> 830356 T2099 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-003/' [junit4] 2> 830391 T2099 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-003/solr.xml [junit4] 2> 830450 T2099 oasc.CoreContainer.<init> New CoreContainer 1047751711 [junit4] 2> 830450 T2099 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-003/] [junit4] 2> 830451 T2099 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 830451 T2099 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 830451 T2099 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 830452 T2099 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 830452 T2099 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 830452 T2099 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 830452 T2099 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 830452 T2099 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 830453 T2099 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 830453 T2099 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 830453 T2099 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 830454 T2099 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 830454 T2099 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 830454 T2099 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:31502/solr [junit4] 2> 830454 T2099 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 830455 T2099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 830455 T2099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 830457 T2144 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bbf8741 name:ZooKeeperConnection Watcher:127.0.0.1:31502 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 830457 T2099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 830458 T2099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 830459 T2099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 830460 T2146 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7da355d3 name:ZooKeeperConnection Watcher:127.0.0.1:31502/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 830460 T2099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 830463 T2099 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 831466 T2099 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:31516_mvdt [junit4] 2> 831467 T2099 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:31516_mvdt [junit4] 2> 831469 T2099 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 831474 T2148 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 831474 T2148 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 831475 T2148 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 831475 T2126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 831476 T2122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:31516/mvdt", [junit4] 2> "roles":null, [junit4] 2> "collection":"collection1", [junit4] 2> "shard":null, [junit4] 2> "state":"down", [junit4] 2> "node_name":"127.0.0.1:31516_mvdt", [junit4] 2> "operation":"state", [junit4] 2> "numShards":"1"} [junit4] 2> 831477 T2122 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1] [junit4] 2> 831477 T2122 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 1 [junit4] 2> 831477 T2122 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 831478 T2147 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> 831478 T2133 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> 831478 T2126 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> 832475 T2148 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 832476 T2148 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 832476 T2148 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 832476 T2148 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 832477 T2148 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 832477 T2148 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-003/collection1/' [junit4] 2> 832478 T2148 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-003/collection1/lib/README' to classloader [junit4] 2> 832479 T2148 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-003/collection1/lib/.svn/' to classloader [junit4] 2> 832479 T2148 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-003/collection1/lib/classes/' to classloader [junit4] 2> 832523 T2148 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0 [junit4] 2> 832556 T2148 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 832657 T2148 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 832665 T2148 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 832921 T2148 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 832923 T2148 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 832925 T2148 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 832928 T2148 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 832945 T2148 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 832946 T2148 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory [junit4] 2> 832946 T2148 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-003/collection1/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty1/ [junit4] 2> 832946 T2148 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@697c1b7e [junit4] 2> 832947 T2148 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty1 [junit4] 2> 832948 T2148 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty1/index/ [junit4] 2> 832948 T2148 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty1/index' doesn't exist. Creating new index... [junit4] 2> 832949 T2148 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty1/index [junit4] 2> 832950 T2148 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=50.662109375, floorSegmentMB=0.794921875, forceMergeDeletesPctAllowed=9.61346083338408, segmentsPerTier=30.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.11871855456068783 [junit4] 2> 832953 T2148 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1} [junit4] 2> 832953 T2148 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 832958 T2148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 832958 T2148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 832958 T2148 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 832959 T2148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 832959 T2148 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 832959 T2148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 832959 T2148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 832960 T2148 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 832960 T2148 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 832960 T2148 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 832961 T2148 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 832961 T2148 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 832961 T2148 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 832962 T2148 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 832962 T2148 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 832962 T2148 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 832963 T2148 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 832963 T2148 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 832963 T2148 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 832964 T2148 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 832976 T2148 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 832977 T2148 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 832978 T2148 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 832980 T2148 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 832982 T2148 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 832983 T2148 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 832983 T2148 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.49973849721668306] [junit4] 2> 832985 T2148 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1} [junit4] 2> 832985 T2148 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 832985 T2148 oass.SolrIndexSearcher.<init> Opening Searcher@eba0df9[collection1] main [junit4] 2> 832985 T2148 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 832986 T2148 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 832986 T2148 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 832987 T2148 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 832987 T2148 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 832987 T2148 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 832987 T2148 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 832988 T2148 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 832988 T2148 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 832988 T2148 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 832991 T2149 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@eba0df9[collection1] main{UninvertingDirectoryReader()} [junit4] 2> 832994 T2148 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 832995 T2152 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:31516/mvdt collection:collection1 shard:shard1 [junit4] 2> 832995 T2099 oass.SolrDispatchFilter.init user.dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1 [junit4] 2> 832995 T2099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 832995 T2152 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 832999 T2152 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 833000 T2126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 833000 T2152 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 833000 T2152 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C218 name=collection1 org.apache.solr.core.SolrCore@145334b6 url=http://127.0.0.1:31516/mvdt/collection1 node=127.0.0.1:31516_mvdt C218_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:31516/mvdt, state=down, node_name=127.0.0.1:31516_mvdt} [junit4] 2> 833000 T2152 C218 P31516 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:31516/mvdt/collection1/ [junit4] 2> 833001 T2152 C218 P31516 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 833001 T2152 C218 P31516 oasc.SyncStrategy.syncToMe http://127.0.0.1:31516/mvdt/collection1/ has no replicas [junit4] 2> 833001 T2152 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:31516/mvdt/collection1/ shard1 [junit4] 2> 833001 T2152 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 833003 T2126 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> 833003 T2147 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> 833003 T2133 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> 833007 T2126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 833007 T2126 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> 833007 T2147 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> 833007 T2133 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> 833054 T2152 oasc.ZkController.register We are http://127.0.0.1:31516/mvdt/collection1/ and leader is http://127.0.0.1:31516/mvdt/collection1/ [junit4] 2> 833055 T2152 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:31516/mvdt [junit4] 2> 833055 T2152 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 833055 T2152 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 833055 T2152 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 833056 T2126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 833058 T2122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "base_url":"http://127.0.0.1:31516/mvdt", [junit4] 2> "roles":null, [junit4] 2> "collection":"collection1", [junit4] 2> "shard":"shard1", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1:31516_mvdt", [junit4] 2> "operation":"state", [junit4] 2> "numShards":"1"} [junit4] 2> 833161 T2126 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> 833161 T2133 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> 833161 T2147 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> 833953 T2099 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 [junit4] 2> 833955 T2099 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 833958 T2099 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13772 [junit4] 2> 833958 T2099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 833959 T2099 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 833959 T2099 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-004 [junit4] 2> 833959 T2099 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-004/' [junit4] 2> 833991 T2099 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-004/solr.xml [junit4] 2> 834049 T2099 oasc.CoreContainer.<init> New CoreContainer 513608649 [junit4] 2> 834050 T2099 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-004/] [junit4] 2> 834050 T2099 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 834051 T2099 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 834051 T2099 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 834051 T2099 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 834051 T2099 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 834052 T2099 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 834052 T2099 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 834052 T2099 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 834052 T2099 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 834053 T2099 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 834053 T2099 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 834053 T2099 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 834053 T2099 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 834054 T2099 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:31502/solr [junit4] 2> 834054 T2099 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 834054 T2099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 834055 T2099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 834056 T2163 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5870c8d2 name:ZooKeeperConnection Watcher:127.0.0.1:31502 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 834057 T2099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 834057 T2099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 834058 T2099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 834059 T2165 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@41cceaa8 name:ZooKeeperConnection Watcher:127.0.0.1:31502/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 834059 T2099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 834063 T2099 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 835066 T2099 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13772_mvdt [junit4] 2> 835067 T2099 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13772_mvdt [junit4] 2> 835070 T2099 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 835076 T2167 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 835076 T2167 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 835077 T2167 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 835077 T2126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 835080 T2122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:13772/mvdt", [junit4] 2> "roles":null, [junit4] 2> "collection":"collection1", [junit4] 2> "shard":null, [junit4] 2> "state":"down", [junit4] 2> "node_name":"127.0.0.1:13772_mvdt", [junit4] 2> "operation":"state", [junit4] 2> "numShards":"1"} [junit4] 2> 835080 T2122 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1 [junit4] 2> 835080 T2122 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 835082 T2133 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 835082 T2147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 835082 T2166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 835082 T2126 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 836078 T2167 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 836079 T2167 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 836080 T2167 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 836080 T2167 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 836081 T2167 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 836081 T2167 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-004/collection1/' [junit4] 2> 836084 T2167 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-004/collection1/lib/classes/' to classloader [junit4] 2> 836086 T2167 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-004/collection1/lib/README' to classloader [junit4] 2> 836087 T2167 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-004/collection1/lib/.svn/' to classloader [junit4] 2> 836187 T2167 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0 [junit4] 2> 836249 T2167 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 836350 T2167 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 836362 T2167 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 836901 T2167 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 836906 T2167 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 836909 T2167 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 836917 T2167 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 836940 T2167 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 836941 T2167 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory [junit4] 2> 836941 T2167 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-004/collection1/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2/ [junit4] 2> 836941 T2167 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@697c1b7e [junit4] 2> 836943 T2167 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2 [junit4] 2> 836944 T2167 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2/index/ [junit4] 2> 836945 T2167 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2/index' doesn't exist. Creating new index... [junit4] 2> 836946 T2167 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2/index [junit4] 2> 836947 T2167 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=50.662109375, floorSegmentMB=0.794921875, forceMergeDeletesPctAllowed=9.61346083338408, segmentsPerTier=30.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.11871855456068783 [junit4] 2> 836953 T2167 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1} [junit4] 2> 836953 T2167 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 836963 T2167 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 836964 T2167 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 836965 T2167 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 836965 T2167 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 836966 T2167 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 836966 T2167 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 836967 T2167 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 836967 T2167 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 836967 T2167 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 836969 T2167 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 836970 T2167 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 836970 T2167 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 836971 T2167 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 836972 T2167 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 836973 T2167 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 836973 T2167 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 836974 T2167 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 836975 T2167 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 836976 T2167 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 836977 T2167 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 837041 T2167 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 837044 T2167 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 837046 T2167 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 837048 T2167 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 837052 T2167 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 837052 T2167 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 837053 T2167 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.49973849721668306] [junit4] 2> 837055 T2167 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1} [junit4] 2> 837056 T2167 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 837056 T2167 oass.SolrIndexSearcher.<init> Opening Searcher@2f08762e[collection1] main [junit4] 2> 837056 T2167 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 837057 T2167 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 837057 T2167 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 837058 T2167 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 837058 T2167 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 837058 T2167 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 837059 T2167 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 837060 T2167 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 837060 T2167 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 837060 T2167 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 837065 T2168 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2f08762e[collection1] main{UninvertingDirectoryReader()} [junit4] 2> 837069 T2167 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 837070 T2171 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:13772/mvdt collection:collection1 shard:shard1 [junit4] 2> 837070 T2099 oass.SolrDispatchFilter.init user.dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1 [junit4] 2> 837071 T2099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 837073 T2171 oasc.ZkController.register We are http://127.0.0.1:13772/mvdt/collection1/ and leader is http://127.0.0.1:31516/mvdt/collection1/ [junit4] 2> 837073 T2171 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:13772/mvdt [junit4] 2> 837073 T2171 oasc.ZkController.checkRecovery Core needs to recover:collection1 [junit4] 2> 837074 T2171 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery [junit4] 2> 837074 T2099 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):330 [junit4] 2> ASYNC NEW_CORE C219 name=collection1 org.apache.solr.core.SolrCore@156258b4 url=http://127.0.0.1:13772/mvdt/collection1 node=127.0.0.1:13772_mvdt C219_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:13772/mvdt, state=down, node_name=127.0.0.1:13772_mvdt} [junit4] 2> 837074 T2172 C219 P13772 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true [junit4] 2> 837075 T2172 C219 P13772 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[] [junit4] 2> 837076 T2172 C219 P13772 oasc.RecoveryStrategy.doRecovery Publishing state of core collection1 as recovering, leader is http://127.0.0.1:31516/mvdt/collection1/ and I am http://127.0.0.1:13772/mvdt/collection1/ [junit4] 2> 837076 T2172 C219 P13772 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1 [junit4] 2> 837076 T2172 C219 P13772 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 837078 T2126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 837080 T2172 C219 P13772 oasc.RecoveryStrategy.sendPrepRecoveryCmd Sending prep recovery command to http://127.0.0.1:31516/mvdt; WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1%3A13772_mvdt&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true [junit4] 2> 837083 T2139 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true [junit4] 2> 837085 T2122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node2", [junit4] 2> "base_url":"http://127.0.0.1:13772/mvdt", [junit4] 2> "roles":null, [junit4] 2> "collection":"collection1", [junit4] 2> "shard":"shard1", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"127.0.0.1:13772_mvdt", [junit4] 2> "operation":"state", [junit4] 2> "numShards":"1"} [junit4] 2> 837087 T2139 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering [junit4] 2> 837087 T2139 oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:13772_mvdt, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"core":"collection1","base_url":"http://127.0.0.1:13772/mvdt","state":"down","node_name":"127.0.0.1:13772_mvdt"} [junit4] 2> 837095 T2166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 837095 T2147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 837095 T2126 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 837095 T2133 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 838089 T2139 oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:13772_mvdt, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"core":"collection1","base_url":"http://127.0.0.1:13772/mvdt","state":"recovering","node_name":"127.0.0.1:13772_mvdt"} [junit4] 2> 838089 T2139 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds. [junit4] 2> 838090 T2139 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={checkLive=true&nodeName=127.0.0.1:13772_mvdt&core=collection1&action=PREPRECOVERY&coreNodeName=core_node2&version=2&onlyIfLeader=true&wt=javabin&state=recovering&onlyIfLeaderActive=true} status=0 QTime=1007 [junit4] 2> C219_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:13772/mvdt, state=recovering, node_name=127.0.0.1:13772_mvdt} [junit4] 2> 840091 T2172 C219 P13772 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:31516/mvdt/collection1/ core=collection1 - recoveringAfterStartup=true [junit4] 2> 840092 T2172 C219 P13772 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:13772/mvdt START replicas=[http://127.0.0.1:31516/mvdt/collection1/] nUpdates=100 [junit4] 2> 840093 T2172 C219 P13772 oasu.PeerSync.sync WARN no frame of reference to tell if we've missed updates [junit4] 2> 840394 T2172 C219 P13772 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1 [junit4] 2> 840396 T2172 C219 P13772 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1 [junit4] 2> 840396 T2172 C219 P13772 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1 [junit4] 2> 840396 T2172 C219 P13772 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null} [junit4] 2> 840397 T2172 C219 P13772 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:31516/mvdt/collection1/. core=collection1 [junit4] 2> ASYNC NEW_CORE C220 name=collection1 org.apache.solr.core.SolrCore@145334b6 url=http://127.0.0.1:31516/mvdt/collection1 node=127.0.0.1:31516_mvdt C220_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:31516/mvdt, state=active, node_name=127.0.0.1:31516_mvdt, leader=true} [junit4] 2> 840399 T2139 C220 P31516 oasc.SolrCore.execute [collection1] webapp=/mvdt path=/get params={qt=/get&version=2&wt=javabin&getVersions=100&distrib=false} status=0 QTime=1 [junit4] 2> 840400 T2141 C220 P31516 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 840401 T2141 C220 P31516 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit. [junit4] 2> 840405 T2141 C220 P31516 oasu.DirectUpdateHandler2.commit end_commit_flush [junit4] 2> 840405 T2141 C220 P31516 oasup.LogUpdateProcessor.finish [collection1] webapp=/mvdt path=/update params={commit_end_point=true&waitSearcher=true&version=2&openSearcher=false&wt=javabin&softCommit=false&commit=true} {commit=} 0 5 [junit4] 2> 840407 T2172 C219 P13772 oash.ReplicationHandler.inform Commits will be reserved for 10000 [junit4] 2> 840407 T2172 C219 P13772 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started. [junit4] 2> 840412 T2139 C220 P31516 oash.ReplicationHandler.inform Commits will be reserved for 10000 [junit4] 2> 840413 T2139 C220 P31516 oasc.SolrCore.execute [collection1] webapp=/mvdt path=/replication params={qt=/replication&command=indexversion&version=2&wt=javabin} status=0 QTime=3 [junit4] 2> 840414 T2172 C219 P13772 oasc.RecoveryStrategy.replay No replay needed. core=collection1 [junit4] 2> 840414 T2172 C219 P13772 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1 [junit4] 2> 840415 T2172 C219 P13772 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 840415 T2172 C219 P13772 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 840417 T2172 C219 P13772 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1 [junit4] 2> 840417 T2126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 840421 T2122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node2", [junit4] 2> "base_url":"http://127.0.0.1:13772/mvdt", [junit4] 2> "roles":null, [junit4] 2> "collection":"collection1", [junit4] 2> "shard":"shard1", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1:13772_mvdt", [junit4] 2> "operation":"state", [junit4] 2> "numShards":"1"} [junit4] 2> 840425 T2126 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 840425 T2147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 840425 T2166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 840425 T2133 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 841088 T2099 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1 [junit4] 2> ASYNC NEW_CORE C221 name=collection1 org.apache.solr.core.SolrCore@319f5a8e url=http://127.0.0.1:31505/mvd [...truncated too long message...] n1] CLOSING SolrCore org.apache.solr.core.SolrCore@156258b4 [junit4] 2> 987683 T2191 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node2", [junit4] 2> "base_url":"http://127.0.0.1:13772/mvdt", [junit4] 2> "roles":null, [junit4] 2> "collection":"collection1", [junit4] 2> "shard":"shard1", [junit4] 2> "state":"down", [junit4] 2> "node_name":"127.0.0.1:13772_mvdt", [junit4] 2> "operation":"state"} [junit4] 2> 987688 T2099 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=76,cumulative_deletesById=37,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=8736,transaction_logs_total_number=1} [junit4] 2> 987689 T2099 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState [junit4] 2> 987690 T2099 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter [junit4] 2> 987690 T2099 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser [junit4] 2> 987693 T2099 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request. [junit4] 2> 987694 T2099 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked [junit4] 2> 987694 T2099 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2 [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2;done=false>>] [junit4] 2> 987694 T2190 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> 987695 T2099 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2 [junit4] 2> 987695 T2099 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2/index [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2/index;done=false>>] [junit4] 2> 987696 T2099 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001/tempDir-001/jetty2/index [junit4] 2> 987696 T2099 oasc.Overseer.close Overseer (id=92479026354192392-127.0.0.1:13772_mvdt-n_0000000002) closing [junit4] 2> 987698 T2191 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:13772_mvdt [junit4] 2> 987699 T2194 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:347) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:344) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:344) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:383) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:126) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:333) [junit4] 2> [junit4] 2> 989199 T2190 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 989201 T2099 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/mvdt,null} [junit4] 2> 994203 T2099 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch [junit4] 2> 994206 T2099 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:31502 31502 [junit4] 2> 995309 T2100 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:31502 31502 [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyNothingIsSafeTest -Dtests.method=testDistribSearch -Dtests.seed=F1EDE8D81D56886D -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=sq -Dtests.timezone=MET -Dtests.file.encoding=UTF-8 [junit4] FAILURE 171s J1 | ChaosMonkeyNothingIsSafeTest.testDistribSearch <<< [junit4] > Throwable #1: java.lang.AssertionError: There were too many update fails - we expect it can happen, but shouldn't easily [junit4] > at __randomizedtesting.SeedInfo.seed([F1EDE8D81D56886D:700B66C06A09E851]:0) [junit4] > at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:223) [junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] 2> 995335 T2099 oas.SolrTestCaseJ4.deleteCore ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-F1EDE8D81D56886D-001 [junit4] 2> NOTE: test params are: codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=427), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=427)), sim=DefaultSimilarity, locale=sq, timezone=MET [junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_65 (64-bit)/cpus=16,threads=1,free=137482168,total=284688384 [junit4] 2> NOTE: All tests run in this JVM: [DirectSolrConnectionTest, URLClassifyProcessorTest, TestCoreDiscovery, ResponseLogComponentTest, ConnectionManagerTest, TestSolrIndexConfig, TestManagedSchemaDynamicFieldResource, TestRequestStatusCollectionAPI, TestCSVResponseWriter, TestFastWriter, TestSchemaNameResource, HdfsSyncSliceTest, BlockDirectoryTest, SystemInfoHandlerTest, TestArbitraryIndexDir, HdfsBasicDistributedZk2Test, TestSolrCoreProperties, TestStressUserVersions, TestCollationFieldDocValues, TestLMDirichletSimilarityFactory, SuggestComponentTest, TestDefaultSearchFieldResource, DistributedDebugComponentTest, TestExpandComponent, BJQParserTest, TestFieldCollectionResource, CopyFieldTest, TestFastLRUCache, TestSystemIdResolver, DOMUtilTest, HighlighterConfigTest, DistributedTermsComponentTest, TestSolrXmlPersistence, TestCloudManagedSchema, HdfsBasicDistributedZkTest, OverriddenZkACLAndCredentialsProvidersTest, TestNonDefinedSimilarityFactory, CollectionsAPIAsyncDistributedZkTest, TestInitQParser, AddBlockUpdateTest, SampleTest, UniqFieldsUpdateProcessorFactoryTest, TestDistributedSearch, ShardRoutingTest, TestSurroundQueryParser, TestSchemaResource, TestClassNameShortening, TestFiltering, TestPhraseSuggestions, StressHdfsTest, RollingRestartTest, DeleteLastCustomShardedReplicaTest, ChaosMonkeyNothingIsSafeTest] [junit4] Completed on J1 in 171.15s, 1 test, 1 failure <<< FAILURES! [...truncated 764 lines...] BUILD FAILED /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:491: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:471: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:60: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/extra-targets.xml:39: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build.xml:189: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/common-build.xml:496: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/lucene/common-build.xml:1358: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/lucene/common-build.xml:961: There were test failures: 429 suites, 1772 tests, 1 failure, 59 ignored (24 assumptions) Total time: 52 minutes 8 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Sending artifact delta relative to Lucene-Solr-Tests-5.x-Java7 #2117 Archived 5 artifacts Archive block size is 32768 Received 0 blocks and 165301085 bytes Compression is 0.0% Took 27 sec Recording test results Email was triggered for: Failure Sending email for trigger: Failure
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org