You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/01/04 19:56:14 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 2256 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/2256/
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch
Error Message:
There were expected update fails expected:<0> but was:<1>
Stack Trace:
java.lang.AssertionError: There were expected update fails expected:<0> but was:<1>
at __randomizedtesting.SeedInfo.seed([943E3C71EC6A9DC7:15D8B2699B35FDFB]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:202)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:849)
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:616)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:679)
Build Log:
[...truncated 9951 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
[junit4] 2> 445535 T969 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /bk_ezw/
[junit4] 2> 445540 T969 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeyNothingIsSafeTest-1388860003406
[junit4] 2> 445541 T969 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 445541 T970 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 445642 T969 oasc.ZkTestServer.run start zk server on port:13203
[junit4] 2> 445644 T969 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 445674 T977 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a6316d2 name:ZooKeeperConnection Watcher:127.0.0.1:13203 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 445674 T969 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 445675 T969 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 445705 T969 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 445717 T980 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4839dab0 name:ZooKeeperConnection Watcher:127.0.0.1:13203/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 445718 T969 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 445719 T969 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 445723 T969 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 445732 T969 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 445735 T969 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 445739 T969 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 445740 T969 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 445750 T969 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 445751 T969 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 445856 T969 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 445857 T969 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 445866 T969 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 445867 T969 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 445871 T969 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 445871 T969 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 445876 T969 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 445876 T969 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 445880 T969 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 445881 T969 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 445884 T969 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 445885 T969 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 445889 T969 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 445890 T969 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 445893 T969 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 445894 T969 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 445897 T969 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 445898 T969 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 446214 T969 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 446219 T969 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13206
[junit4] 2> 446220 T969 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 446220 T969 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 446221 T969 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388860003769
[junit4] 2> 446221 T969 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388860003769/'
[junit4] 2> 446270 T969 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388860003769/solr.xml
[junit4] 2> 446351 T969 oasc.CoreContainer.<init> New CoreContainer 700601949
[junit4] 2> 446352 T969 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388860003769/]
[junit4] 2> 446354 T969 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 446354 T969 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 446355 T969 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 446355 T969 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 446356 T969 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 446356 T969 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 446357 T969 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 446357 T969 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 446358 T969 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 446370 T969 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 446371 T969 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 446371 T969 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 446372 T969 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:13203/solr
[junit4] 2> 446372 T969 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 446374 T969 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 446504 T992 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ec08e7b name:ZooKeeperConnection Watcher:127.0.0.1:13203 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 446505 T969 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 446523 T969 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 446525 T995 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@46ff4791 name:ZooKeeperConnection Watcher:127.0.0.1:13203/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 446525 T969 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 446528 T969 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 446538 T969 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 446542 T969 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 446545 T969 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13206_bk_ezw
[junit4] 2> 446552 T969 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13206_bk_ezw
[junit4] 2> 446557 T969 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 446560 T969 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 446572 T969 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 446575 T969 oasc.Overseer.start Overseer (id=91020329183674371-127.0.0.1:13206_bk_ezw-n_0000000000) starting
[junit4] 2> 446586 T969 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 446600 T997 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 446601 T969 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 446604 T969 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 446607 T969 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 446611 T996 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 446616 T998 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 446617 T998 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 446619 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 446619 T998 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 446620 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 446621 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:13206/bk_ezw",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:13206_bk_ezw",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 446622 T996 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 446622 T996 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 446626 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 446635 T995 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> 447621 T998 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 447621 T998 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388860003769/collection1
[junit4] 2> 447621 T998 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 447622 T998 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 447622 T998 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 447624 T998 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388860003769/collection1/'
[junit4] 2> 447625 T998 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388860003769/collection1/lib/classes/' to classloader
[junit4] 2> 447626 T998 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388860003769/collection1/lib/README' to classloader
[junit4] 2> 447679 T998 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 447725 T998 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 447828 T998 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 447836 T998 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 448263 T998 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 448267 T998 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 448269 T998 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 448274 T998 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 448302 T998 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 448340 T998 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388860003769/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/control/data/
[junit4] 2> 448340 T998 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@149c8281
[junit4] 2> 448341 T998 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/control/data
[junit4] 2> 448342 T998 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/control/data/index/
[junit4] 2> 448342 T998 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 448344 T998 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/control/data/index
[junit4] 2> 448344 T998 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=932399651, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 448348 T998 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 448349 T998 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 448351 T998 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 448352 T998 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 448352 T998 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 448352 T998 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 448353 T998 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 448353 T998 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 448353 T998 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 448353 T998 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 448354 T998 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 448354 T998 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 448355 T998 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 448355 T998 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 448355 T998 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 448355 T998 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 448356 T998 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 448356 T998 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 448364 T998 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 448368 T998 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 448368 T998 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 448369 T998 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1952518064, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 448370 T998 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 448370 T998 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 448371 T998 oass.SolrIndexSearcher.<init> Opening Searcher@45955a00 main
[junit4] 2> 448373 T999 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@45955a00 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 448374 T998 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 448375 T969 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4] 2> 448375 T969 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 448375 T1002 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:13206/bk_ezw collection:control_collection shard:shard1
[junit4] 2> 448377 T969 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 448378 T1002 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 448380 T1005 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fae42b5 name:ZooKeeperConnection Watcher:127.0.0.1:13203/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 448381 T969 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 448390 T969 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 448402 T969 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 448403 T1002 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 448414 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 448414 T1002 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 448415 T1002 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C642 name=collection1 org.apache.solr.core.SolrCore@7b8509c8 url=http://127.0.0.1:13206/bk_ezw/collection1 node=127.0.0.1:13206_bk_ezw C642_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:13206/bk_ezw, core=collection1, node_name=127.0.0.1:13206_bk_ezw}
[junit4] 2> 448415 T1002 C642 P13206 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:13206/bk_ezw/collection1/
[junit4] 2> 448415 T1002 C642 P13206 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 448416 T1002 C642 P13206 oasc.SyncStrategy.syncToMe http://127.0.0.1:13206/bk_ezw/collection1/ has no replicas
[junit4] 2> 448416 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 448416 T1002 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:13206/bk_ezw/collection1/ shard1
[junit4] 2> 448416 T1002 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 448427 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 448429 T1005 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> 448429 T995 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> 448449 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 448453 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 448557 T1005 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> 448557 T995 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> 448601 T1002 oasc.ZkController.register We are http://127.0.0.1:13206/bk_ezw/collection1/ and leader is http://127.0.0.1:13206/bk_ezw/collection1/
[junit4] 2> 448601 T1002 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:13206/bk_ezw
[junit4] 2> 448601 T1002 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 448601 T1002 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 448601 T1002 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 448603 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 448603 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 448603 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 448604 T1002 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 448605 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 448606 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:13206/bk_ezw",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:13206_bk_ezw",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 448614 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 448718 T1005 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> 448718 T995 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> 448787 T969 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 448791 T969 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13210
[junit4] 2> 448792 T969 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 448792 T969 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 448793 T969 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388860006268
[junit4] 2> 448793 T969 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388860006268/'
[junit4] 2> 448844 T969 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388860006268/solr.xml
[junit4] 2> 448941 T969 oasc.CoreContainer.<init> New CoreContainer 1686657986
[junit4] 2> 448941 T969 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388860006268/]
[junit4] 2> 448943 T969 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 448944 T969 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 448944 T969 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 448945 T969 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 448945 T969 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 448946 T969 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 448946 T969 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 448946 T969 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 448947 T969 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 448959 T969 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 448959 T969 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 448960 T969 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 448960 T969 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:13203/solr
[junit4] 2> 448961 T969 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 448962 T969 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 448965 T1017 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78e0a6f8 name:ZooKeeperConnection Watcher:127.0.0.1:13203 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 448965 T969 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 448969 T969 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 448976 T1020 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26ccfa2d name:ZooKeeperConnection Watcher:127.0.0.1:13203/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 448977 T969 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 448983 T969 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 449988 T969 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13210_bk_ezw
[junit4] 2> 449992 T969 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13210_bk_ezw
[junit4] 2> 450060 T1005 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 450060 T995 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 450060 T1020 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 450071 T1021 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 450071 T1021 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 450073 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 450073 T1021 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 450073 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 450074 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 450075 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 450076 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:13210/bk_ezw",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:13210_bk_ezw",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 450077 T996 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 450077 T996 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 450114 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 450217 T995 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> 450217 T1020 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> 450217 T1005 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> 451074 T1021 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 451074 T1021 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388860006268/collection1
[junit4] 2> 451074 T1021 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 451076 T1021 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 451076 T1021 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 451077 T1021 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388860006268/collection1/'
[junit4] 2> 451078 T1021 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388860006268/collection1/lib/README' to classloader
[junit4] 2> 451079 T1021 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388860006268/collection1/lib/classes/' to classloader
[junit4] 2> 451139 T1021 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 451199 T1021 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 451302 T1021 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 451314 T1021 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 451919 T1021 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 451923 T1021 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 451926 T1021 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 451932 T1021 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 451962 T1021 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 451963 T1021 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388860006268/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty1/
[junit4] 2> 451963 T1021 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@149c8281
[junit4] 2> 451965 T1021 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty1
[junit4] 2> 451966 T1021 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty1/index/
[junit4] 2> 451967 T1021 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 451968 T1021 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty1/index
[junit4] 2> 451969 T1021 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=932399651, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 451973 T1021 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 451974 T1021 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 451978 T1021 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 451979 T1021 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 451979 T1021 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 451979 T1021 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 451980 T1021 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 451980 T1021 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 451981 T1021 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 451981 T1021 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 451981 T1021 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 451982 T1021 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 451983 T1021 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 451983 T1021 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 451983 T1021 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 451984 T1021 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 451985 T1021 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 451985 T1021 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 451997 T1021 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 452001 T1021 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 452001 T1021 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 452002 T1021 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1952518064, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 452004 T1021 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 452004 T1021 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 452005 T1021 oass.SolrIndexSearcher.<init> Opening Searcher@28d0c75c main
[junit4] 2> 452009 T1022 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@28d0c75c main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 452011 T1021 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 452012 T969 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4] 2> 452013 T969 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 452012 T1025 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:13210/bk_ezw collection:collection1 shard:shard1
[junit4] 2> 452015 T1025 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 452037 T1025 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 452045 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452046 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452046 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452046 T1025 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 452046 T1025 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C643 name=collection1 org.apache.solr.core.SolrCore@5563c744 url=http://127.0.0.1:13210/bk_ezw/collection1 node=127.0.0.1:13210_bk_ezw C643_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:13210/bk_ezw, core=collection1, node_name=127.0.0.1:13210_bk_ezw}
[junit4] 2> 452046 T1025 C643 P13210 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:13210/bk_ezw/collection1/
[junit4] 2> 452047 T1025 C643 P13210 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 452047 T1025 C643 P13210 oasc.SyncStrategy.syncToMe http://127.0.0.1:13210/bk_ezw/collection1/ has no replicas
[junit4] 2> 452047 T1025 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:13210/bk_ezw/collection1/ shard1
[junit4] 2> 452047 T1025 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 452047 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 452060 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452062 T1005 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> 452062 T1020 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> 452062 T995 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> 452072 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 452081 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452185 T1020 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> 452185 T995 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> 452185 T1005 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> 452224 T1025 oasc.ZkController.register We are http://127.0.0.1:13210/bk_ezw/collection1/ and leader is http://127.0.0.1:13210/bk_ezw/collection1/
[junit4] 2> 452224 T1025 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:13210/bk_ezw
[junit4] 2> 452224 T1025 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 452224 T1025 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 452224 T1025 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 452226 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452226 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452227 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452227 T1025 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 452228 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 452229 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:13210/bk_ezw",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:13210_bk_ezw",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 452233 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 452329 T969 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 452332 T969 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13213
[junit4] 2> 452332 T969 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 452333 T969 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 452333 T969 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388860009880
[junit4] 2> 452334 T969 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388860009880/'
[junit4] 2> 452336 T1005 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> 452336 T1020 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> 452336 T995 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> 452374 T969 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388860009880/solr.xml
[junit4] 2> 452459 T969 oasc.CoreContainer.<init> New CoreContainer 196965361
[junit4] 2> 452460 T969 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388860009880/]
[junit4] 2> 452462 T969 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 452462 T969 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 452463 T969 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 452463 T969 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 452464 T969 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 452464 T969 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 452465 T969 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 452465 T969 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 452466 T969 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 452476 T969 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 452476 T969 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 452477 T969 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 452477 T969 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:13203/solr
[junit4] 2> 452478 T969 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 452480 T969 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 452482 T1037 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76a01484 name:ZooKeeperConnection Watcher:127.0.0.1:13203 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 452483 T969 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 452487 T969 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 452494 T1040 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35806f5 name:ZooKeeperConnection Watcher:127.0.0.1:13203/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 452495 T969 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 452501 T969 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 453506 T969 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13213_bk_ezw
[junit4] 2> 453509 T969 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13213_bk_ezw
[junit4] 2> 453513 T1005 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 453513 T1040 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 453513 T1020 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 453513 T995 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 453528 T1041 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 453528 T1041 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 453530 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 453530 T1041 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 453531 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 453531 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 453533 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 453533 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:13213/bk_ezw",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:13213_bk_ezw",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 453534 T996 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 453534 T996 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 453537 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 453651 T1005 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> 453651 T1040 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> 453651 T1020 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> 453651 T995 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> 454532 T1041 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 454532 T1041 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388860009880/collection1
[junit4] 2> 454532 T1041 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 454533 T1041 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 454533 T1041 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 454535 T1041 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388860009880/collection1/'
[junit4] 2> 454536 T1041 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388860009880/collection1/lib/README' to classloader
[junit4] 2> 454536 T1041 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388860009880/collection1/lib/classes/' to classloader
[junit4] 2> 454583 T1041 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 454644 T1041 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 454747 T1041 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 454759 T1041 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 455343 T1041 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 455348 T1041 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 455351 T1041 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 455356 T1041 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 455387 T1041 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 455387 T1041 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388860009880/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty2/
[junit4] 2> 455387 T1041 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@149c8281
[junit4] 2> 455389 T1041 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty2
[junit4] 2> 455390 T1041 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty2/index/
[junit4] 2> 455391 T1041 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 455392 T1041 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty2/index
[junit4] 2> 455393 T1041 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=932399651, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 455401 T1041 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 455401 T1041 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 455406 T1041 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 455407 T1041 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 455407 T1041 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 455407 T1041 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 455408 T1041 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 455408 T1041 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 455408 T1041 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 455409 T1041 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 455409 T1041 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 455410 T1041 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 455411 T1041 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 455411 T1041 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 455411 T1041 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 455412 T1041 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 455412 T1041 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 455413 T1041 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 455423 T1041 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 455427 T1041 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 455427 T1041 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 455428 T1041 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1952518064, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 455430 T1041 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 455430 T1041 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 455431 T1041 oass.SolrIndexSearcher.<init> Opening Searcher@37af2017 main
[junit4] 2> 455436 T1042 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@37af2017 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 455438 T1041 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 455439 T969 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4] 2> 455440 T969 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 455439 T1045 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:13213/bk_ezw collection:collection1 shard:shard2
[junit4] 2> 455442 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 455456 T1045 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 455464 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455464 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455464 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455464 T1045 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 455465 T1045 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C644 name=collection1 org.apache.solr.core.SolrCore@1e76f170 url=http://127.0.0.1:13213/bk_ezw/collection1 node=127.0.0.1:13213_bk_ezw C644_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:13213/bk_ezw, core=collection1, node_name=127.0.0.1:13213_bk_ezw}
[junit4] 2> 455465 T1045 C644 P13213 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:13213/bk_ezw/collection1/
[junit4] 2> 455465 T1045 C644 P13213 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 455466 T1045 C644 P13213 oasc.SyncStrategy.syncToMe http://127.0.0.1:13213/bk_ezw/collection1/ has no replicas
[junit4] 2> 455466 T1045 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:13213/bk_ezw/collection1/ shard2
[junit4] 2> 455466 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 455466 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 455471 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455479 T1005 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> 455479 T1020 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> 455479 T1040 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> 455479 T995 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> 455492 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 455503 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455608 T1005 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> 455608 T1020 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> 455608 T995 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> 455608 T1040 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> 455643 T1045 oasc.ZkController.register We are http://127.0.0.1:13213/bk_ezw/collection1/ and leader is http://127.0.0.1:13213/bk_ezw/collection1/
[junit4] 2> 455643 T1045 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:13213/bk_ezw
[junit4] 2> 455643 T1045 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 455643 T1045 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 455644 T1045 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 455645 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455646 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455646 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455646 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 455647 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 455648 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:13213/bk_ezw",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:13213_bk_ezw",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 455659 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455765 T1005 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> 455765 T1020 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> 455765 T995 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> 455765 T1040 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> 455805 T969 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 455808 T969 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13220
[junit4] 2> 455809 T969 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 455810 T969 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 455810 T969 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388860013307
[junit4] 2> 455811 T969 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388860013307/'
[junit4] 2> 455858 T969 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388860013307/solr.xml
[junit4] 2> 455953 T969 oasc.CoreContainer.<init> New CoreContainer 445675256
[junit4] 2> 455953 T969 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388860013307/]
[junit4] 2> 455955 T969 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 455956 T969 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 455956 T969 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 455957 T969 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 455957 T969 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 455958 T969 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 455958 T969 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 455958 T969 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 455959 T969 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 455973 T969 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 455974 T969 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 455974 T969 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 455975 T969 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:13203/solr
[junit4] 2> 455975 T969 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 455977 T969 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 455980 T1057 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33c2b419 name:ZooKeeperConnection Watcher:127.0.0.1:13203 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 455981 T969 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 455993 T969 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 456003 T1060 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e213863 name:ZooKeeperConnection Watcher:127.0.0.1:13203/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 456003 T969 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 456020 T969 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 457024 T969 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13220_bk_ezw
[junit4] 2> 457054 T969 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13220_bk_ezw
[junit4] 2> 457059 T1005 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 457059 T995 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 457060 T1060 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 457060 T1020 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 457059 T1040 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 457072 T1061 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 457072 T1061 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 457074 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 457074 T1061 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 457074 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 457075 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 457076 T996 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 457077 T996 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:13220/bk_ezw",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:13220_bk_ezw",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 457078 T996 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 457078 T996 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 457082 T995 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 457186 T1060 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 457186 T1020 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 457186 T1040 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 457186 T995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 457186 T1005 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 458075 T1061 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 458075 T1061 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388860013307/collection1
[junit4] 2> 458075 T1061 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 458076 T1061 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 458077 T1061 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 458078 T1061 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388860013307/collection1/'
[junit4] 2> 458079 T1061 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388860013307/collection1/lib/README' to classloader
[junit4] 2> 458080 T1061 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388860013307/collection1/lib/classes/' to classloader
[junit4] 2> 458146 T1061 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 458217 T1061 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 458319 T1061 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 458331 T1061 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 458930 T1061 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 458934 T1061 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 458936 T1061 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 458942 T1061 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 458971 T1061 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 458971 T1061 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388860013307/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty3/
[junit4] 2> 458972 T1061 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@149c8281
[junit4] 2> 458973 T1061 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty3
[junit4] 2> 458974 T1061 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty3/index/
[junit4] 2> 458975 T1061 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 458976 T1061 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty3/index
[junit4] 2> 458977 T1061 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=932399651, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 458983 T1061 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 458983 T1061 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 458988 T1061 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 458988 T1061 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 458988 T1061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 458989 T1061 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 458989 T1061 oasup.UpdateRequestProcessorChain.init inserting
[...truncated too long message...]
ld/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty7/index' does not exist
[junit4] 2> at org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:219)
[junit4] 2> at org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:243)
[junit4] 2> at org.apache.solr.core.DirectoryFactory.sizeOfDirectory(DirectoryFactory.java:191)
[junit4] 2> at org.apache.solr.handler.ReplicationHandler.getIndexSize(ReplicationHandler.java:521)
[junit4] 2> at org.apache.solr.handler.ReplicationHandler.getStatistics(ReplicationHandler.java:562)
[junit4] 2> at org.apache.solr.core.RequestHandlers$LazyRequestHandlerWrapper.getStatistics(RequestHandlers.java:318)
[junit4] 2> at org.apache.solr.core.JmxMonitoredMap$SolrDynamicMBean.getMBeanInfo(JmxMonitoredMap.java:236)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getClassName(DefaultMBeanServerInterceptor.java:1823)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.safeGetClassName(DefaultMBeanServerInterceptor.java:1660)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1832)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:436)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:421)
[junit4] 2> at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:550)
[junit4] 2> at org.apache.solr.core.JmxMonitoredMap.unregister(JmxMonitoredMap.java:175)
[junit4] 2> at org.apache.solr.core.JmxMonitoredMap.clear(JmxMonitoredMap.java:116)
[junit4] 2> at org.apache.solr.core.SolrCore.close(SolrCore.java:1011)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:268)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 550725 T1147 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=67,cumulative_deletesById=29,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=1}
[junit4] 2> 550725 T1147 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 550725 T1147 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 550725 T1147 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 550727 T1147 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 550728 T1147 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 550728 T1147 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty7/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty7/index;done=false>>]
[junit4] 2> 550728 T1147 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty7/index
[junit4] 2> 550728 T1147 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty7 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty7;done=false>>]
[junit4] 2> 550729 T1147 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388860003406/jetty7
[junit4] 2> 550729 T1147 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 550729 T1147 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> NOTE: test params are: codec=Lucene46: {id=PostingsFormat(name=SimpleText), a_t=MockFixedIntBlock(blockSize=521), _version_=MockFixedIntBlock(blockSize=521), a_si=PostingsFormat(name=MockSep)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=bg_BG, timezone=Europe/Luxembourg
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=4,free=166248456,total=397082624
[junit4] 2> NOTE: All tests run in this JVM: [StressHdfsTest, TestCoreDiscovery, HdfsSyncSliceTest, TestRangeQuery, TestAnalyzedSuggestions, TestRTGBase, SuggesterWFSTTest, RequiredFieldsTest, TestRandomFaceting, SolrCmdDistributorTest, TestSchemaVersionResource, FileUtilsTest, TestOmitPositions, TestIBSimilarityFactory, DocumentAnalysisRequestHandlerTest, TestComponentsName, TestIndexingPerformance, TestArbitraryIndexDir, AssignTest, SpellingQueryConverterTest, CoreMergeIndexesAdminHandlerTest, TestCollationKeyRangeQueries, NumericFieldsTest, CurrencyFieldOpenExchangeTest, TestSolrXmlPersistence, DisMaxRequestHandlerTest, OutputWriterTest, TestDynamicFieldCollectionResource, TestFiltering, StandardRequestHandlerTest, TestDistributedMissingSort, ConvertedLegacyTest, TestAtomicUpdateErrorCases, TestQuerySenderNoQuery, ConnectionManagerTest, NotRequiredUniqueKeyTest, SolrRequestParserTest, TestDefaultSimilarityFactory, TestSolrQueryParserResource, BlockDirectoryTest, TestDFRSimilarityFactory, FullSolrCloudDistribCmdsTest, TestClassNameShortening, FieldAnalysisRequestHandlerTest, TestSweetSpotSimilarityFactory, TestMaxScoreQueryParser, SignatureUpdateProcessorFactoryTest, TestReload, MinimalSchemaTest, TestStressReorder, HdfsRecoveryZkTest, TestStressLucene, TestBinaryResponseWriter, TimeZoneUtilsTest, TestCollationField, TestFuzzyAnalyzedSuggestions, TestFastWriter, TestHashPartitioner, AddBlockUpdateTest, XmlUpdateRequestHandlerTest, TestFieldResource, DebugComponentTest, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed on J1 in 105.24s, 1 test, 1 failure <<< FAILURES!
[...truncated 633 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:459: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:439: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1307: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:940: There were test failures: 348 suites, 1522 tests, 1 failure, 35 ignored (6 assumptions)
Total time: 61 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 2257 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/2257/
1 tests failed.
FAILED: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch
Error Message:
There were expected update fails expected:<0> but was:<2>
Stack Trace:
java.lang.AssertionError: There were expected update fails expected:<0> but was:<2>
at __randomizedtesting.SeedInfo.seed([4CAEF5C34040B703:CD487BDB371FD73F]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:202)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:849)
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:616)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:679)
Build Log:
[...truncated 9457 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
[junit4] 2> 268054 T630 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /fp_n/
[junit4] 2> 268061 T630 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeyNothingIsSafeTest-1388916908643
[junit4] 2> 268062 T630 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 268063 T631 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 268164 T630 oasc.ZkTestServer.run start zk server on port:24937
[junit4] 2> 268166 T630 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 268171 T638 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f410c84 name:ZooKeeperConnection Watcher:127.0.0.1:24937 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 268172 T630 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 268172 T630 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 268188 T630 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 268190 T641 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6536c16e name:ZooKeeperConnection Watcher:127.0.0.1:24937/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 268191 T630 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 268191 T630 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 268202 T630 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 268206 T630 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 268209 T630 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 268213 T630 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 268214 T630 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 268228 T630 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 268229 T630 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 268235 T630 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 268235 T630 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 268240 T630 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 268241 T630 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 268252 T630 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 268253 T630 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 268258 T630 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 268259 T630 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 268270 T630 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 268270 T630 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 268275 T630 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 268276 T630 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 268280 T630 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 268281 T630 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 268285 T630 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 268286 T630 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 268291 T630 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 268292 T630 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 268584 T630 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 268588 T630 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:24940
[junit4] 2> 268589 T630 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 268589 T630 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 268590 T630 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388916908879
[junit4] 2> 268590 T630 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388916908879/'
[junit4] 2> 268631 T630 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388916908879/solr.xml
[junit4] 2> 268716 T630 oasc.CoreContainer.<init> New CoreContainer 1087555910
[junit4] 2> 268717 T630 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388916908879/]
[junit4] 2> 268719 T630 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 268719 T630 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 268720 T630 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 268720 T630 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 268721 T630 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 268721 T630 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 268722 T630 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 268722 T630 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 268723 T630 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 268734 T630 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 268734 T630 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 268735 T630 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 268735 T630 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24937/solr
[junit4] 2> 268736 T630 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 268738 T630 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 268742 T653 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63ecc02f name:ZooKeeperConnection Watcher:127.0.0.1:24937 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 268744 T630 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 268748 T630 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 268755 T656 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39b83c86 name:ZooKeeperConnection Watcher:127.0.0.1:24937/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 268756 T630 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 268758 T630 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 268764 T630 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 268774 T630 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 268781 T630 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:24940_fp_n
[junit4] 2> 268783 T630 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:24940_fp_n
[junit4] 2> 268792 T630 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 268795 T630 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 268818 T630 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 268827 T630 oasc.Overseer.start Overseer (id=91024058525286403-127.0.0.1:24940_fp_n-n_0000000000) starting
[junit4] 2> 268840 T630 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 268846 T658 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 268847 T630 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 268850 T630 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 268853 T630 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 268857 T657 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 268862 T659 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 268862 T659 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 268864 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 268864 T659 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 268866 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 268867 T657 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:24940/fp_n",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:24940_fp_n",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 268867 T657 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 268867 T657 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 268871 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 268872 T656 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> 269865 T659 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 269865 T659 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388916908879/collection1
[junit4] 2> 269865 T659 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 269867 T659 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 269867 T659 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 269868 T659 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388916908879/collection1/'
[junit4] 2> 269870 T659 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388916908879/collection1/lib/README' to classloader
[junit4] 2> 269870 T659 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388916908879/collection1/lib/classes/' to classloader
[junit4] 2> 269936 T659 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 270006 T659 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 270008 T659 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 270019 T659 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 270631 T659 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 270636 T659 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 270638 T659 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 270645 T659 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 270684 T659 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 270752 T659 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1388916908879/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/control/data/
[junit4] 2> 270752 T659 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b9d09e2
[junit4] 2> 270755 T659 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/control/data
[junit4] 2> 270756 T659 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/control/data/index/
[junit4] 2> 270757 T659 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 270759 T659 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/control/data/index
[junit4] 2> 270760 T659 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=38, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4348628778592023]
[junit4] 2> 270765 T659 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 270766 T659 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 270771 T659 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 270771 T659 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 270772 T659 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 270772 T659 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 270772 T659 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 270773 T659 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 270773 T659 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 270774 T659 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 270774 T659 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 270775 T659 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 270776 T659 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 270776 T659 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 270776 T659 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 270777 T659 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 270777 T659 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 270778 T659 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 270792 T659 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 270797 T659 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 270797 T659 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 270798 T659 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=22, maxMergedSegmentMB=42.3173828125, floorSegmentMB=1.0966796875, forceMergeDeletesPctAllowed=18.11116669432812, segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.619803360340806
[junit4] 2> 270800 T659 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 270801 T659 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 270801 T659 oass.SolrIndexSearcher.<init> Opening Searcher@7ce0745e main
[junit4] 2> 270805 T660 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7ce0745e main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 270808 T659 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 270809 T630 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4] 2> 270810 T630 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 270809 T663 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:24940/fp_n collection:control_collection shard:shard1
[junit4] 2> 270812 T630 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 270812 T663 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 270815 T666 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c319b83 name:ZooKeeperConnection Watcher:127.0.0.1:24937/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 270815 T630 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 270838 T630 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 270858 T630 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 270860 T663 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 270871 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 270872 T663 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 270872 T663 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C307 name=collection1 org.apache.solr.core.SolrCore@76088b4b url=http://127.0.0.1:24940/fp_n/collection1 node=127.0.0.1:24940_fp_n C307_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:24940/fp_n, core=collection1, node_name=127.0.0.1:24940_fp_n}
[junit4] 2> 270873 T663 C307 P24940 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:24940/fp_n/collection1/
[junit4] 2> 270873 T663 C307 P24940 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 270873 T663 C307 P24940 oasc.SyncStrategy.syncToMe http://127.0.0.1:24940/fp_n/collection1/ has no replicas
[junit4] 2> 270873 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 270874 T663 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:24940/fp_n/collection1/ shard1
[junit4] 2> 270874 T663 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 270879 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 270889 T666 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> 270889 T656 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> 270901 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 270906 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 271010 T656 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> 271011 T666 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> 271053 T663 oasc.ZkController.register We are http://127.0.0.1:24940/fp_n/collection1/ and leader is http://127.0.0.1:24940/fp_n/collection1/
[junit4] 2> 271053 T663 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:24940/fp_n
[junit4] 2> 271053 T663 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 271053 T663 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 271054 T663 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 271055 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 271056 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 271056 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 271056 T663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 271058 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 271059 T657 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:24940/fp_n",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:24940_fp_n",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 271063 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 271166 T656 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> 271166 T666 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> 271203 T630 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 271207 T630 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:24950
[junit4] 2> 271208 T630 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 271208 T630 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 271209 T630 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388916911439
[junit4] 2> 271209 T630 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388916911439/'
[junit4] 2> 271247 T630 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388916911439/solr.xml
[junit4] 2> 271327 T630 oasc.CoreContainer.<init> New CoreContainer 1071794018
[junit4] 2> 271328 T630 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388916911439/]
[junit4] 2> 271330 T630 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 271330 T630 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 271331 T630 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 271331 T630 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 271332 T630 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 271332 T630 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 271333 T630 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 271333 T630 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 271334 T630 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 271346 T630 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 271346 T630 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 271347 T630 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 271347 T630 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24937/solr
[junit4] 2> 271348 T630 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 271349 T630 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 271352 T678 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c849be8 name:ZooKeeperConnection Watcher:127.0.0.1:24937 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 271353 T630 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 271357 T630 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 271359 T681 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@717e84b8 name:ZooKeeperConnection Watcher:127.0.0.1:24937/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 271359 T630 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 271370 T630 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 272375 T630 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:24950_fp_n
[junit4] 2> 272416 T630 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:24950_fp_n
[junit4] 2> 272421 T666 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 272421 T681 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 272421 T656 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 272472 T682 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 272472 T682 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 272474 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 272474 T682 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 272474 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 272475 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 272477 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 272478 T657 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:24950/fp_n",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:24950_fp_n",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 272478 T657 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 272478 T657 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 272513 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 272616 T681 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> 272616 T666 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> 272616 T656 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> 273476 T682 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 273476 T682 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388916911439/collection1
[junit4] 2> 273477 T682 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 273478 T682 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 273478 T682 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 273480 T682 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388916911439/collection1/'
[junit4] 2> 273481 T682 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388916911439/collection1/lib/README' to classloader
[junit4] 2> 273482 T682 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388916911439/collection1/lib/classes/' to classloader
[junit4] 2> 273551 T682 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 273625 T682 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 273727 T682 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 273738 T682 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 274369 T682 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 274373 T682 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 274376 T682 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 274382 T682 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 274418 T682 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 274419 T682 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1388916911439/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty1/
[junit4] 2> 274419 T682 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b9d09e2
[junit4] 2> 274421 T682 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty1
[junit4] 2> 274422 T682 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty1/index/
[junit4] 2> 274423 T682 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 274424 T682 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty1/index
[junit4] 2> 274425 T682 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=38, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4348628778592023]
[junit4] 2> 274436 T682 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 274436 T682 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 274442 T682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 274443 T682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 274443 T682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 274444 T682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 274444 T682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 274444 T682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 274445 T682 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 274445 T682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 274446 T682 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 274446 T682 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 274447 T682 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 274447 T682 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 274448 T682 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 274449 T682 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 274449 T682 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 274450 T682 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 274464 T682 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 274469 T682 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 274469 T682 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 274470 T682 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=22, maxMergedSegmentMB=42.3173828125, floorSegmentMB=1.0966796875, forceMergeDeletesPctAllowed=18.11116669432812, segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.619803360340806
[junit4] 2> 274472 T682 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 274473 T682 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 274473 T682 oass.SolrIndexSearcher.<init> Opening Searcher@763c80e8 main
[junit4] 2> 274478 T683 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@763c80e8 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 274481 T682 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 274482 T630 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4] 2> 274483 T630 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 274482 T686 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:24950/fp_n collection:collection1 shard:shard1
[junit4] 2> 274485 T686 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 274504 T686 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 274514 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 274514 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 274515 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 274515 T686 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 274515 T686 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C308 name=collection1 org.apache.solr.core.SolrCore@7a18830c url=http://127.0.0.1:24950/fp_n/collection1 node=127.0.0.1:24950_fp_n C308_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:24950/fp_n, core=collection1, node_name=127.0.0.1:24950_fp_n}
[junit4] 2> 274515 T686 C308 P24950 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:24950/fp_n/collection1/
[junit4] 2> 274516 T686 C308 P24950 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 274516 T686 C308 P24950 oasc.SyncStrategy.syncToMe http://127.0.0.1:24950/fp_n/collection1/ has no replicas
[junit4] 2> 274516 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 274516 T686 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:24950/fp_n/collection1/ shard1
[junit4] 2> 274517 T686 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 274528 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 274530 T656 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> 274530 T681 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> 274530 T666 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> 274547 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 274551 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 274654 T656 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> 274654 T681 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> 274654 T666 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> 274698 T686 oasc.ZkController.register We are http://127.0.0.1:24950/fp_n/collection1/ and leader is http://127.0.0.1:24950/fp_n/collection1/
[junit4] 2> 274698 T686 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:24950/fp_n
[junit4] 2> 274698 T686 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 274698 T686 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 274699 T686 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 274701 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 274701 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 274701 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 274701 T686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 274703 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 274704 T657 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:24950/fp_n",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:24950_fp_n",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 274707 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 274765 T630 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 274768 T630 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:24959
[junit4] 2> 274769 T630 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 274770 T630 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 274770 T630 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388916915065
[junit4] 2> 274771 T630 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388916915065/'
[junit4] 2> 274805 T630 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388916915065/solr.xml
[junit4] 2> 274811 T656 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> 274811 T681 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> 274811 T666 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> 274885 T630 oasc.CoreContainer.<init> New CoreContainer 1471413820
[junit4] 2> 274885 T630 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388916915065/]
[junit4] 2> 274887 T630 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 274888 T630 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 274888 T630 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 274889 T630 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 274889 T630 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 274890 T630 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 274890 T630 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 274891 T630 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 274891 T630 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 274903 T630 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 274904 T630 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 274904 T630 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 274905 T630 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24937/solr
[junit4] 2> 274905 T630 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 274907 T630 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 274910 T698 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29bd3793 name:ZooKeeperConnection Watcher:127.0.0.1:24937 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 274911 T630 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 274914 T630 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 274916 T701 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@203d793 name:ZooKeeperConnection Watcher:127.0.0.1:24937/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 274917 T630 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 274927 T630 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 275931 T630 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:24959_fp_n
[junit4] 2> 275933 T630 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:24959_fp_n
[junit4] 2> 275938 T666 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 275938 T656 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 275938 T701 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 275938 T681 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 275948 T702 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 275948 T702 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 275950 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 275950 T702 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 275950 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 275950 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 275952 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 275953 T657 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:24959/fp_n",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:24959_fp_n",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 275953 T657 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 275953 T657 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 275957 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 276060 T681 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> 276060 T701 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> 276060 T656 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> 276060 T666 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> 276951 T702 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 276951 T702 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388916915065/collection1
[junit4] 2> 276951 T702 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 276952 T702 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 276953 T702 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 276954 T702 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388916915065/collection1/'
[junit4] 2> 276955 T702 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388916915065/collection1/lib/classes/' to classloader
[junit4] 2> 276956 T702 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388916915065/collection1/lib/README' to classloader
[junit4] 2> 277021 T702 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 277085 T702 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 277187 T702 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 277198 T702 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 277828 T702 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 277833 T702 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 277835 T702 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 277841 T702 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 277875 T702 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 277875 T702 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1388916915065/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty2/
[junit4] 2> 277875 T702 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b9d09e2
[junit4] 2> 277877 T702 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty2
[junit4] 2> 277878 T702 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty2/index/
[junit4] 2> 277879 T702 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 277885 T702 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty2/index
[junit4] 2> 277886 T702 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=38, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4348628778592023]
[junit4] 2> 277895 T702 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 277896 T702 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 277902 T702 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 277902 T702 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 277903 T702 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 277903 T702 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 277903 T702 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 277904 T702 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 277904 T702 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 277905 T702 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 277905 T702 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 277906 T702 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 277906 T702 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 277907 T702 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 277907 T702 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 277908 T702 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 277908 T702 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 277909 T702 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 277923 T702 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 277927 T702 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 277928 T702 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 277929 T702 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=22, maxMergedSegmentMB=42.3173828125, floorSegmentMB=1.0966796875, forceMergeDeletesPctAllowed=18.11116669432812, segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.619803360340806
[junit4] 2> 277931 T702 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 277931 T702 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 277931 T702 oass.SolrIndexSearcher.<init> Opening Searcher@3f0762f6 main
[junit4] 2> 277937 T703 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3f0762f6 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 277940 T702 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 277941 T630 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4] 2> 277941 T630 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 277941 T706 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:24959/fp_n collection:collection1 shard:shard2
[junit4] 2> 277943 T706 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 277959 T706 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 277967 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 277967 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 277967 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 277967 T706 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 277967 T706 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C309 name=collection1 org.apache.solr.core.SolrCore@59a1485e url=http://127.0.0.1:24959/fp_n/collection1 node=127.0.0.1:24959_fp_n C309_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:24959/fp_n, core=collection1, node_name=127.0.0.1:24959_fp_n}
[junit4] 2> 277968 T706 C309 P24959 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:24959/fp_n/collection1/
[junit4] 2> 277968 T706 C309 P24959 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 277968 T706 C309 P24959 oasc.SyncStrategy.syncToMe http://127.0.0.1:24959/fp_n/collection1/ has no replicas
[junit4] 2> 277969 T706 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:24959/fp_n/collection1/ shard2
[junit4] 2> 277969 T706 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 277969 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 277982 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 277984 T681 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> 277984 T701 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> 277984 T666 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> 277984 T656 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> 277990 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 278001 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 278107 T681 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> 278107 T701 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> 278107 T656 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> 278107 T666 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> 278140 T706 oasc.ZkController.register We are http://127.0.0.1:24959/fp_n/collection1/ and leader is http://127.0.0.1:24959/fp_n/collection1/
[junit4] 2> 278140 T706 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:24959/fp_n
[junit4] 2> 278140 T706 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 278140 T706 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 278141 T706 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 278143 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 278143 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 278143 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 278143 T706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 278145 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 278146 T657 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:24959/fp_n",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:24959_fp_n",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 278150 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 278253 T681 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> 278253 T701 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> 278253 T666 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> 278253 T656 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> 278262 T630 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 278265 T630 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:24968
[junit4] 2> 278266 T630 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 278266 T630 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 278267 T630 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388916918523
[junit4] 2> 278267 T630 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388916918523/'
[junit4] 2> 278305 T630 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388916918523/solr.xml
[junit4] 2> 278384 T630 oasc.CoreContainer.<init> New CoreContainer 1142132071
[junit4] 2> 278385 T630 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388916918523/]
[junit4] 2> 278386 T630 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 278387 T630 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 278387 T630 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 278388 T630 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 278388 T630 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 278389 T630 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 278389 T630 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 278390 T630 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 278390 T630 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 278402 T630 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 278403 T630 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 278403 T630 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 278404 T630 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24937/solr
[junit4] 2> 278404 T630 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 278405 T630 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 278410 T718 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@317fd5ad name:ZooKeeperConnection Watcher:127.0.0.1:24937 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 278411 T630 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 278414 T630 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 278423 T721 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6957b94b name:ZooKeeperConnection Watcher:127.0.0.1:24937/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 278423 T630 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 278429 T630 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 279433 T630 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:24968_fp_n
[junit4] 2> 279435 T630 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:24968_fp_n
[junit4] 2> 279440 T666 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 279440 T681 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 279440 T721 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 279440 T656 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 279440 T701 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 279450 T722 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 279450 T722 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 279452 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 279452 T722 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 279452 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 279452 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 279454 T657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 279455 T657 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:24968/fp_n",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:24968_fp_n",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 279455 T657 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 279456 T657 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 279459 T656 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 279563 T666 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 279563 T701 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 279563 T721 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 279563 T656 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 279563 T681 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 280453 T722 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 280453 T722 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388916918523/collection1
[junit4] 2> 280453 T722 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 280454 T722 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 280454 T722 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 280456 T722 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388916918523/collection1/'
[junit4] 2> 280457 T722 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388916918523/collection1/lib/README' to classloader
[junit4] 2> 280458 T722 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388916918523/collection1/lib/classes/' to classloader
[junit4] 2> 280523 T722 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 280599 T722 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 280700 T722 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 280711 T722 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 281348 T722 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 281353 T722 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 281355 T722 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 281361 T722 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 281395 T722 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 281396 T722 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1388916918523/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty3/
[junit4] 2> 281396 T722 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b9d09e2
[junit4] 2> 281398 T722 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty3
[junit4] 2> 281399 T722 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty3/index/
[junit4] 2> 281400 T722 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 281402 T722 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty3/index
[junit4] 2> 281402 T722 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=38, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4348628778592023]
[junit4] 2> 281420 T722 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 281421 T722 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 281427 T722 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 281427 T722 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 281428 T722 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 281428 T722 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 281429 T722 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 281429 T722 oasup.UpdateRequestProcessorChain.init creating upda
[...truncated too long message...]
DirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 471621 T764 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty5/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty5/index;done=false>>]
[junit4] 2> 471621 T764 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty5/index
[junit4] 2> 471621 T764 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty5 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty5;done=false>>]
[junit4] 2> 471622 T764 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty5
[junit4] 2> 471622 T764 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 471622 T764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 471622 T764 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 471623 T764 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 471676 T786 C339 P25003 oasc.SyncStrategy.sync WARN Closed, skipping sync up.
[junit4] 2> 471676 T786 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4] 2> 471677 T786 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@262b58c9
[junit4] 2> 471680 T786 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=71,cumulative_deletesById=34,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=1}
[junit4] 2> 471680 T786 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 471681 T786 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 471681 T786 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 471682 T786 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 471682 T786 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 471682 T786 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty6/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty6/index;done=false>>]
[junit4] 2> 471683 T786 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty6/index
[junit4] 2> 471683 T786 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty6 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty6;done=false>>]
[junit4] 2> 471683 T786 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1388916908642/jetty6
[junit4] 2> 471683 T786 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 471684 T786 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=sl, timezone=PRC
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=94888912,total=423297024
[junit4] 2> NOTE: All tests run in this JVM: [TestSchemaVersionResource, SpellCheckComponentTest, NotRequiredUniqueKeyTest, XmlUpdateRequestHandlerTest, TestFastOutputStream, HighlighterTest, TestBinaryResponseWriter, TestDistributedSearch, TestIBSimilarityFactory, TestStressReorder, TestStressLucene, SuggesterTSTTest, TestFiltering, TestManagedSchemaFieldResource, CurrencyFieldOpenExchangeTest, PingRequestHandlerTest, ConvertedLegacyTest, HighlighterConfigTest, DebugComponentTest, TestDistribDocBasedVersion, DistanceFunctionTest, SpellingQueryConverterTest, TestIndexSearcher, MinimalSchemaTest, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed on J1 in 203.73s, 1 test, 1 failure <<< FAILURES!
[...truncated 847 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:459: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:439: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1307: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:940: There were test failures: 348 suites, 1522 tests, 1 failure, 35 ignored (6 assumptions)
Total time: 64 minutes 3 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure