You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/11/20 11:04:53 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 1040
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1040/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch
Error Message:
document count mismatch. control=199 sum(shards)=200 cloudClient=200
Stack Trace:
java.lang.AssertionError: document count mismatch. control=199 sum(shards)=200 cloudClient=200
at __randomizedtesting.SeedInfo.seed([D57EF05674A4E216:54987E4E03FB822A]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1238)
at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:196)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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:744)
Build Log:
[...truncated 10119 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
[junit4] 2> 885759 T2329 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /s_e/tc
[junit4] 2> 885767 T2329 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeyNothingIsSafeTest-1384939392187
[junit4] 2> 885768 T2329 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 885769 T2330 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 885871 T2329 oasc.ZkTestServer.run start zk server on port:49866
[junit4] 2> 885872 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 885879 T2336 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dd818d name:ZooKeeperConnection Watcher:127.0.0.1:49866 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 885879 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 885880 T2329 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 885893 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 885899 T2338 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ce3a5e8 name:ZooKeeperConnection Watcher:127.0.0.1:49866/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 885900 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 885900 T2329 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 885907 T2329 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 885914 T2329 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 885921 T2329 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 885929 T2329 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 885929 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 885941 T2329 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 885942 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 885950 T2329 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 885951 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 885959 T2329 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 885959 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 885968 T2329 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 885969 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 885977 T2329 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 885977 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 885984 T2329 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 885985 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 885992 T2329 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 885993 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 886000 T2329 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 886001 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 886009 T2329 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 886010 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 886016 T2329 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 886017 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 886354 T2329 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 886359 T2329 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49869
[junit4] 2> 886361 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 886361 T2329 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 886361 T2329 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1384939392446
[junit4] 2> 886362 T2329 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1384939392446/'
[junit4] 2> 886398 T2329 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1384939392446/solr.xml
[junit4] 2> 886462 T2329 oasc.CoreContainer.<init> New CoreContainer 905578167
[junit4] 2> 886463 T2329 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1384939392446/]
[junit4] 2> 886464 T2329 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 886465 T2329 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 886465 T2329 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 886465 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 886465 T2329 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 886465 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 886466 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 886466 T2329 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 886466 T2329 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 886470 T2329 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 886471 T2329 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 886471 T2329 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 886471 T2329 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49866/solr
[junit4] 2> 886472 T2329 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 886473 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 886478 T2349 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@530c9e81 name:ZooKeeperConnection Watcher:127.0.0.1:49866 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 886479 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 886485 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 886490 T2351 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d8a3272 name:ZooKeeperConnection Watcher:127.0.0.1:49866/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 886490 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 886495 T2329 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 886504 T2329 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 886512 T2329 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 886516 T2329 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49869_s_e%2Ftc
[junit4] 2> 886519 T2329 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49869_s_e%2Ftc
[junit4] 2> 886528 T2329 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 886543 T2329 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 886549 T2329 oasc.Overseer.start Overseer (id=90763388006694915-127.0.0.1:49869_s_e%2Ftc-n_0000000000) starting
[junit4] 2> 886559 T2329 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 886571 T2353 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 886572 T2329 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 886579 T2329 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 886584 T2329 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 886594 T2352 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 886604 T2354 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 886604 T2354 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 886607 T2354 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 888106 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 888108 T2352 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:49869/s_e/tc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49869_s_e%2Ftc",
[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> 888108 T2352 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 888108 T2352 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 888117 T2351 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> 888609 T2354 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 888610 T2354 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1384939392446/collection1
[junit4] 2> 888610 T2354 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 888611 T2354 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 888612 T2354 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 888614 T2354 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1384939392446/collection1/'
[junit4] 2> 888615 T2354 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1384939392446/collection1/lib/classes/' to classloader
[junit4] 2> 888616 T2354 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1384939392446/collection1/lib/README' to classloader
[junit4] 2> 888680 T2354 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 888741 T2354 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 888745 T2354 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 888759 T2354 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 889330 T2354 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 889339 T2354 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 889343 T2354 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 889375 T2354 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 889381 T2354 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 889392 T2354 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 889396 T2354 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 889396 T2354 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 889396 T2354 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 889399 T2354 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 889400 T2354 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 889400 T2354 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 889400 T2354 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1384939392446/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/control/data/
[junit4] 2> 889401 T2354 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5ba957e3
[junit4] 2> 889402 T2354 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/control/data
[junit4] 2> 889403 T2354 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/control/data/index/
[junit4] 2> 889404 T2354 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 889405 T2354 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/control/data/index
[junit4] 2> 889406 T2354 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=304865407, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 889411 T2354 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 889411 T2354 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 889416 T2354 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 889417 T2354 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 889418 T2354 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 889418 T2354 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 889418 T2354 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 889419 T2354 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 889420 T2354 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 889420 T2354 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 889420 T2354 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 889421 T2354 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 889422 T2354 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 889422 T2354 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 889422 T2354 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 889423 T2354 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 889424 T2354 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 889424 T2354 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 889438 T2354 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 889444 T2354 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 889444 T2354 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 889445 T2354 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=16, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4161862977071753]
[junit4] 2> 889447 T2354 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 889447 T2354 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 889448 T2354 oass.SolrIndexSearcher.<init> Opening Searcher@551a4678 main
[junit4] 2> 889452 T2355 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@551a4678 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 889455 T2354 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 889455 T2354 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49869/s_e/tc collection:control_collection shard:shard1
[junit4] 2> 889458 T2354 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 889483 T2354 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 889495 T2354 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 889495 T2354 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C4063 name=collection1 org.apache.solr.core.SolrCore@940fa7d url=http://127.0.0.1:49869/s_e/tc/collection1 node=127.0.0.1:49869_s_e%2Ftc C4063_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:49869/s_e/tc, core=collection1, node_name=127.0.0.1:49869_s_e%2Ftc}
[junit4] 2> 889495 T2354 C4063 P49869 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49869/s_e/tc/collection1/
[junit4] 2> 889496 T2354 C4063 P49869 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 889496 T2354 C4063 P49869 oasc.SyncStrategy.syncToMe http://127.0.0.1:49869/s_e/tc/collection1/ has no replicas
[junit4] 2> 889496 T2354 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49869/s_e/tc/collection1/ shard1
[junit4] 2> 889496 T2354 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 889633 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 889656 T2351 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> 889686 T2354 oasc.ZkController.register We are http://127.0.0.1:49869/s_e/tc/collection1/ and leader is http://127.0.0.1:49869/s_e/tc/collection1/
[junit4] 2> 889686 T2354 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49869/s_e/tc
[junit4] 2> 889687 T2354 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 889687 T2354 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 889687 T2354 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 889693 T2354 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 889697 T2329 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 889697 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 889700 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 889705 T2358 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42998500 name:ZooKeeperConnection Watcher:127.0.0.1:49866/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 889705 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 889710 T2329 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 889718 T2329 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 890093 T2329 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 890097 T2329 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49873
[junit4] 2> 890099 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 890100 T2329 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 890100 T2329 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1384939396138
[junit4] 2> 890100 T2329 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1384939396138/'
[junit4] 2> 890141 T2329 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1384939396138/solr.xml
[junit4] 2> 890244 T2329 oasc.CoreContainer.<init> New CoreContainer 1682656646
[junit4] 2> 890244 T2329 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1384939396138/]
[junit4] 2> 890246 T2329 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 890247 T2329 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 890247 T2329 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 890247 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 890248 T2329 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 890248 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 890249 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 890250 T2329 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 890250 T2329 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 890255 T2329 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 890255 T2329 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 890256 T2329 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 890256 T2329 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49866/solr
[junit4] 2> 890257 T2329 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 890258 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 890263 T2369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@127d23d3 name:ZooKeeperConnection Watcher:127.0.0.1:49866 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 890264 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 890271 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 890276 T2371 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45cbb88b name:ZooKeeperConnection Watcher:127.0.0.1:49866/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 890276 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 890289 T2329 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 891173 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 891175 T2352 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:49869/s_e/tc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49869_s_e%2Ftc",
[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":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 891186 T2351 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> 891186 T2371 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> 891187 T2358 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> 891300 T2329 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49873_s_e%2Ftc
[junit4] 2> 891303 T2329 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49873_s_e%2Ftc
[junit4] 2> 891309 T2351 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 891309 T2371 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 891310 T2358 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 891323 T2372 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 891323 T2372 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 891326 T2372 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 892703 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 892705 T2352 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:49873/s_e/tc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49873_s_e%2Ftc",
[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> 892705 T2352 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 892705 T2352 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 892714 T2351 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> 892715 T2358 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> 892714 T2371 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> 893328 T2372 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 893329 T2372 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1384939396138/collection1
[junit4] 2> 893329 T2372 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 893330 T2372 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 893330 T2372 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 893333 T2372 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1384939396138/collection1/'
[junit4] 2> 893335 T2372 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1384939396138/collection1/lib/classes/' to classloader
[junit4] 2> 893336 T2372 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1384939396138/collection1/lib/README' to classloader
[junit4] 2> 893420 T2372 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 893478 T2372 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 893482 T2372 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 893499 T2372 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 894071 T2372 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 894090 T2372 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 894095 T2372 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 894130 T2372 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 894137 T2372 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 894142 T2372 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 894146 T2372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 894147 T2372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 894147 T2372 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 894150 T2372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 894151 T2372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 894151 T2372 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 894151 T2372 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1384939396138/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty1/
[junit4] 2> 894152 T2372 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5ba957e3
[junit4] 2> 894153 T2372 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty1
[junit4] 2> 894153 T2372 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty1/index/
[junit4] 2> 894154 T2372 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 894154 T2372 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty1/index
[junit4] 2> 894156 T2372 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=304865407, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 894159 T2372 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 894160 T2372 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 894164 T2372 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 894164 T2372 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 894165 T2372 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 894165 T2372 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 894165 T2372 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 894165 T2372 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 894166 T2372 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 894166 T2372 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 894166 T2372 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 894168 T2372 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 894168 T2372 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 894169 T2372 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 894169 T2372 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 894170 T2372 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 894170 T2372 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 894170 T2372 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 894180 T2372 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 894183 T2372 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 894184 T2372 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 894184 T2372 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=16, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4161862977071753]
[junit4] 2> 894186 T2372 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 894186 T2372 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 894186 T2372 oass.SolrIndexSearcher.<init> Opening Searcher@30141fc5 main
[junit4] 2> 894193 T2373 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@30141fc5 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 894196 T2372 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 894196 T2372 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49873/s_e/tc collection:collection1 shard:shard1
[junit4] 2> 894198 T2372 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 894217 T2372 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 894224 T2372 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 894224 T2372 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C4064 name=collection1 org.apache.solr.core.SolrCore@733c2aed url=http://127.0.0.1:49873/s_e/tc/collection1 node=127.0.0.1:49873_s_e%2Ftc C4064_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:49873/s_e/tc, core=collection1, node_name=127.0.0.1:49873_s_e%2Ftc}
[junit4] 2> 894224 T2372 C4064 P49873 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49873/s_e/tc/collection1/
[junit4] 2> 894225 T2372 C4064 P49873 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 894225 T2372 C4064 P49873 oasc.SyncStrategy.syncToMe http://127.0.0.1:49873/s_e/tc/collection1/ has no replicas
[junit4] 2> 894225 T2372 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49873/s_e/tc/collection1/ shard1
[junit4] 2> 894225 T2372 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 894226 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 894241 T2358 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> 894241 T2351 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> 894241 T2371 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> 895758 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 895769 T2371 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> 895770 T2351 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> 895772 T2358 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> 895784 T2372 oasc.ZkController.register We are http://127.0.0.1:49873/s_e/tc/collection1/ and leader is http://127.0.0.1:49873/s_e/tc/collection1/
[junit4] 2> 895785 T2372 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49873/s_e/tc
[junit4] 2> 895785 T2372 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 895785 T2372 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 895785 T2372 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 895789 T2372 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 895791 T2329 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 895792 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 896304 T2329 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 896311 T2329 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49876
[junit4] 2> 896313 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 896313 T2329 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 896313 T2329 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1384939402212
[junit4] 2> 896315 T2329 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1384939402212/'
[junit4] 2> 896398 T2329 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1384939402212/solr.xml
[junit4] 2> 896499 T2329 oasc.CoreContainer.<init> New CoreContainer 1287892928
[junit4] 2> 896499 T2329 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1384939402212/]
[junit4] 2> 896501 T2329 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 896501 T2329 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 896501 T2329 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 896502 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 896502 T2329 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 896502 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 896502 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 896503 T2329 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 896503 T2329 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 896507 T2329 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 896507 T2329 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 896507 T2329 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 896508 T2329 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49866/solr
[junit4] 2> 896508 T2329 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 896511 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 896514 T2385 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6835e4fe name:ZooKeeperConnection Watcher:127.0.0.1:49866 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 896515 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 896522 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 896523 T2387 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53c1cdf8 name:ZooKeeperConnection Watcher:127.0.0.1:49866/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 896524 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 896531 T2329 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 897285 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 897287 T2352 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:49873/s_e/tc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49873_s_e%2Ftc",
[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> 897299 T2387 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> 897299 T2358 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> 897300 T2371 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> 897299 T2351 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> 897539 T2329 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49876_s_e%2Ftc
[junit4] 2> 897542 T2329 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49876_s_e%2Ftc
[junit4] 2> 897549 T2358 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 897549 T2371 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 897549 T2351 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 897549 T2387 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 897561 T2388 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 897562 T2388 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 897564 T2388 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 898814 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 898816 T2352 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:49876/s_e/tc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49876_s_e%2Ftc",
[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> 898817 T2352 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 898817 T2352 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 898827 T2358 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> 898829 T2387 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> 898830 T2371 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> 898830 T2351 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> 899567 T2388 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 899567 T2388 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1384939402212/collection1
[junit4] 2> 899567 T2388 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 899569 T2388 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 899569 T2388 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 899572 T2388 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1384939402212/collection1/'
[junit4] 2> 899574 T2388 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1384939402212/collection1/lib/classes/' to classloader
[junit4] 2> 899575 T2388 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1384939402212/collection1/lib/README' to classloader
[junit4] 2> 899630 T2388 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 899688 T2388 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 899692 T2388 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 899700 T2388 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 900239 T2388 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 900247 T2388 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 900250 T2388 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 900278 T2388 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 900284 T2388 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 900289 T2388 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 900292 T2388 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 900293 T2388 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 900293 T2388 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 900296 T2388 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 900296 T2388 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 900297 T2388 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 900297 T2388 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1384939402212/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty2/
[junit4] 2> 900297 T2388 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5ba957e3
[junit4] 2> 900298 T2388 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty2
[junit4] 2> 900299 T2388 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty2/index/
[junit4] 2> 900299 T2388 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 900300 T2388 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty2/index
[junit4] 2> 900300 T2388 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=304865407, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 900303 T2388 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 900303 T2388 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 900307 T2388 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 900308 T2388 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 900308 T2388 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 900308 T2388 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 900309 T2388 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 900309 T2388 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 900309 T2388 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 900310 T2388 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 900310 T2388 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 900310 T2388 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 900311 T2388 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 900311 T2388 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 900312 T2388 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 900312 T2388 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 900313 T2388 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 900313 T2388 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 900328 T2388 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 900332 T2388 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 900333 T2388 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 900333 T2388 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=16, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4161862977071753]
[junit4] 2> 900335 T2388 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 900335 T2388 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 900335 T2388 oass.SolrIndexSearcher.<init> Opening Searcher@563b5cce main
[junit4] 2> 900343 T2389 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@563b5cce main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 900347 T2388 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 900347 T2388 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49876/s_e/tc collection:collection1 shard:shard2
[junit4] 2> 900349 T2388 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 900366 T2388 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 900372 T2388 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 900372 T2388 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C4065 name=collection1 org.apache.solr.core.SolrCore@6117b8c0 url=http://127.0.0.1:49876/s_e/tc/collection1 node=127.0.0.1:49876_s_e%2Ftc C4065_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:49876/s_e/tc, core=collection1, node_name=127.0.0.1:49876_s_e%2Ftc}
[junit4] 2> 900373 T2388 C4065 P49876 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49876/s_e/tc/collection1/
[junit4] 2> 900373 T2388 C4065 P49876 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 900373 T2388 C4065 P49876 oasc.SyncStrategy.syncToMe http://127.0.0.1:49876/s_e/tc/collection1/ has no replicas
[junit4] 2> 900373 T2388 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49876/s_e/tc/collection1/ shard2
[junit4] 2> 900373 T2388 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 901849 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 901870 T2358 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> 901870 T2351 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> 901870 T2387 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> 901871 T2371 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> 901886 T2388 oasc.ZkController.register We are http://127.0.0.1:49876/s_e/tc/collection1/ and leader is http://127.0.0.1:49876/s_e/tc/collection1/
[junit4] 2> 901886 T2388 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49876/s_e/tc
[junit4] 2> 901886 T2388 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 901886 T2388 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 901886 T2388 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 901890 T2388 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 901893 T2329 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 901893 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 902194 T2329 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 902201 T2329 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49879
[junit4] 2> 902204 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 902204 T2329 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 902204 T2329 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1384939408313
[junit4] 2> 902205 T2329 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1384939408313/'
[junit4] 2> 902231 T2329 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1384939408313/solr.xml
[junit4] 2> 902295 T2329 oasc.CoreContainer.<init> New CoreContainer 112213476
[junit4] 2> 902295 T2329 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1384939408313/]
[junit4] 2> 902307 T2329 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 902308 T2329 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 902308 T2329 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 902308 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 902309 T2329 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 902309 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 902309 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 902309 T2329 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 902310 T2329 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 902313 T2329 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 902314 T2329 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 902314 T2329 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 902315 T2329 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49866/solr
[junit4] 2> 902315 T2329 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 902316 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 902321 T2401 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4916294d name:ZooKeeperConnection Watcher:127.0.0.1:49866 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 902322 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 902328 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 902332 T2403 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7353a077 name:ZooKeeperConnection Watcher:127.0.0.1:49866/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 902333 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 902343 T2329 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 903352 T2329 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49879_s_e%2Ftc
[junit4] 2> 903355 T2329 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49879_s_e%2Ftc
[junit4] 2> 903363 T2358 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 903363 T2403 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 903363 T2387 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 903364 T2351 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 903364 T2371 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 903378 T2404 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 903378 T2404 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 903381 T2404 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 903386 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 903388 T2352 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:49876/s_e/tc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49876_s_e%2Ftc",
[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> 903398 T2352 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:49879/s_e/tc",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49879_s_e%2Ftc",
[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> 903399 T2352 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 903399 T2352 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 903409 T2387 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> 903409 T2351 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> 903410 T2371 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> 903409 T2358 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> 903410 T2403 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> 904383 T2404 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 904383 T2404 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1384939408313/collection1
[junit4] 2> 904383 T2404 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 904385 T2404 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 904385 T2404 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 904388 T2404 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1384939408313/collection1/'
[junit4] 2> 904389 T2404 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1384939408313/collection1/lib/classes/' to classloader
[junit4] 2> 904390 T2404 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1384939408313/collection1/lib/README' to classloader
[junit4] 2> 904450 T2404 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 904509 T2404 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 904512 T2404 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 904521 T2404 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 905060 T2404 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 905069 T2404 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 905072 T2404 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 905103 T2404 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 905109 T2404 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 905114 T2404 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 905117 T2404 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 905118 T2404 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 905118 T2404 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 905121 T2404 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 905121 T2404 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 905122 T2404 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 905122 T2404 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1384939408313/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty3/
[junit4] 2> 905122 T2404 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5ba957e3
[junit4] 2> 905123 T2404 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty3
[junit4] 2> 905124 T2404 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty3/index/
[junit4] 2> 905124 T2404 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 905125 T2404 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty3/index
[junit4] 2> 905125 T2404 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=304865407, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 905128 T2404 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 905128 T2404 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 905133 T2404 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 905133 T2404 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 905134 T2404 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 905134 T2404 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 905134 T2404 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 905135 T2404 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 905135 T2404 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 905135 T2404 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 905136 T2404 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 905136 T2404 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 905137 T2404 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 905137 T2404 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 905138 T2404 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 905138 T2404 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 905139 T2404 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 905139 T2404 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 905148 T2404 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 905153 T2404 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 905154 T2404 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 905155 T2404 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=16, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4161862977071753]
[junit4] 2> 905156 T2404 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1384939392186/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 905157 T2404 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 905157 T2404 oass.SolrIndexSearcher.<init> Opening Searcher@6092d74c main
[junit4] 2> 905161 T2405 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6092d74c main{StandardDirectoryReader(segments_1:1
[...truncated too long message...]
nit4] 1> /solr/live_nodes/127.0.0.1:49869_s_e%2Ftc (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:49902_s_e%2Ftc (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:49876_s_e%2Ftc (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:49890_s_e%2Ftc (0)
[junit4] 1> /solr/overseer (3)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1> /solr/overseer/queue (0)
[junit4] 1> /solr/overseer/queue-work (0)
[junit4] 1> /solr/overseer/collection-queue-work (0)
[junit4] 1> /solr/collections (2)
[junit4] 1> /solr/collections/collection1 (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/collection1/shards (0)
[junit4] 1> /solr/collections/collection1/leader_elect (2)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election (3)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90763388006694922-core_node3-n_0000000001 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90763388006694930-core_node7-n_0000000003 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90763388006694926-core_node5-n_0000000002 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard2 (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard2/election (2)
[junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/90763388006694932-core_node2-n_0000000003 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/90763388006694928-core_node6-n_0000000002 (0)
[junit4] 1> /solr/collections/collection1/leaders (2)
[junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:49879_s_e%2Ftc",
[junit4] 1> "base_url":"http://127.0.0.1:49879/s_e/tc"}
[junit4] 1> /solr/collections/collection1/leaders/shard2 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:49897_s_e%2Ftc",
[junit4] 1> "base_url":"http://127.0.0.1:49897/s_e/tc"}
[junit4] 1> /solr/collections/control_collection (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/control_collection/shards (0)
[junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/90763388006694915-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:49869_s_e%2Ftc",
[junit4] 1> "base_url":"http://127.0.0.1:49869/s_e/tc"}
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (6)
[junit4] 1> /solr/overseer_elect/election/90763388006694926-127.0.0.1:49890_s_e%2Ftc-n_0000000005 (0)
[junit4] 1> /solr/overseer_elect/election/90763388006694928-127.0.0.1:49897_s_e%2Ftc-n_0000000006 (0)
[junit4] 1> /solr/overseer_elect/election/90763388006694930-127.0.0.1:49902_s_e%2Ftc-n_0000000007 (0)
[junit4] 1> /solr/overseer_elect/election/90763388006694932-127.0.0.1:49876_s_e%2Ftc-n_0000000008 (0)
[junit4] 1> /solr/overseer_elect/election/90763388006694915-127.0.0.1:49869_s_e%2Ftc-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90763388006694922-127.0.0.1:49879_s_e%2Ftc-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90763388006694915-127.0.0.1:49869_s_e%2Ftc-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyNothingIsSafeTest -Dtests.method=testDistribSearch -Dtests.seed=D57EF05674A4E216 -Dtests.slow=true -Dtests.locale=fr -Dtests.timezone=Asia/Makassar -Dtests.file.encoding=UTF-8
[junit4] FAILURE 88.0s | ChaosMonkeyNothingIsSafeTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: document count mismatch. control=199 sum(shards)=200 cloudClient=200
[junit4] > at __randomizedtesting.SeedInfo.seed([D57EF05674A4E216:54987E4E03FB822A]:0)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1238)
[junit4] > at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:196)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 973775 T2329 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 88023 T2328 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 974010 T2456 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 975118 T2474 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene46: {timestamp=PostingsFormat(name=Memory doPackFST= false), range_facet_l=PostingsFormat(name=Memory doPackFST= false), id=MockVariableIntBlock(baseBlockSize=5), range_facet_sl=Lucene41(blocksize=128), a_t=PostingsFormat(name=Memory doPackFST= false), text=Lucene41(blocksize=128), range_facet_si=PostingsFormat(name=MockSep), _version_=PostingsFormat(name=Memory doPackFST= false), other_tl1=PostingsFormat(name=Memory doPackFST= false), multiDefault=PostingsFormat(name=MockSep), a_si=PostingsFormat(name=MockSep), intDefault=PostingsFormat(name=Memory doPackFST= false)}, docValues:{timestamp=DocValuesFormat(name=Disk)}, sim=DefaultSimilarity, locale=fr, timezone=Asia/Makassar
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=6,free=66245208,total=141615104
[junit4] 2> NOTE: All tests run in this JVM: [SliceStateUpdateTest, BasicDistributedZk2Test, HdfsUnloadDistributedZkTest, TestDefaultSearchFieldResource, TestReversedWildcardFilterFactory, TestDynamicFieldCollectionResource, ResourceLoaderTest, UpdateRequestProcessorFactoryTest, TestMultiCoreConfBootstrap, TestCloudManagedSchema, SolrCoreCheckLockOnStartupTest, TestUniqueKeyFieldResource, DateFieldTest, TestBM25SimilarityFactory, DistributedSpellCheckComponentTest, TestJmxMonitoredMap, BadCopyFieldTest, TestPostingsSolrHighlighter, TestDFRSimilarityFactory, DirectSolrSpellCheckerTest, TestIndexSearcher, TestImplicitCoreProperties, TestRealTimeGet, TestDefaultSimilarityFactory, ParsingFieldUpdateProcessorsTest, RAMDirectoryFactoryTest, DistributedQueryElevationComponentTest, SystemInfoHandlerTest, PolyFieldTest, TestStressRecovery, TestBinaryResponseWriter, TestPHPSerializedResponseWriter, SuggesterWFSTTest, DebugComponentTest, TestReloadAndDeleteDocs, OverseerTest, UpdateParamsTest, AddSchemaFieldsUpdateProcessorFactoryTest, DirectUpdateHandlerOptimizeTest, TestLFUCache, TestAnalyzeInfixSuggestions, TestDocumentBuilder, CoreAdminHandlerTest, UUIDFieldTest, TestDistribDocBasedVersion, TriLevelCompositeIdRoutingTest, TestSchemaResource, TestLRUCache, TestCollationField, SimplePostToolTest, ClusterStateUpdateTest, SignatureUpdateProcessorFactoryTest, TestAnalyzedSuggestions, SuggesterTest, HdfsSyncSliceTest, TestIBSimilarityFactory, TestDocSet, ClusterStateTest, FieldAnalysisRequestHandlerTest, SolrIndexSplitterTest, PrimitiveFieldTypeTest, TestFastWriter, DocValuesTest, TestRangeQuery, AssignTest, TestSweetSpotSimilarityFactory, DOMUtilTest, RequestHandlersTest, MigrateRouteKeyTest, SortByFunctionTest, TestCharFilters, TestZkChroot, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed in 89.57s, 1 test, 1 failure <<< FAILURES!
[...truncated 844 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:420: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:400: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:489: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1272: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:908: There were test failures: 349 suites, 1551 tests, 1 failure, 40 ignored (5 assumptions)
Total time: 86 minutes 51 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 1041
- Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1041/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
reloadcollection the collection time out:60s
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: reloadcollection the collection time out:60s
at __randomizedtesting.SeedInfo.seed([C7010678861941DD:46E78860F14621E1]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:491)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:197)
at org.apache.solr.client.solrj.request.CollectionAdminRequest.process(CollectionAdminRequest.java:271)
at org.apache.solr.client.solrj.request.CollectionAdminRequest.reloadCollection(CollectionAdminRequest.java:346)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:292)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:195)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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:744)
Build Log:
[...truncated 10070 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> 503497 T1361 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 503504 T1361 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1384957098856
[junit4] 2> 503506 T1361 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 503507 T1362 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 503609 T1361 oasc.ZkTestServer.run start zk server on port:49398
[junit4] 2> 503610 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 503619 T1368 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d8cf6a0 name:ZooKeeperConnection Watcher:127.0.0.1:49398 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 503619 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 503619 T1361 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 503632 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 503636 T1370 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@379559e3 name:ZooKeeperConnection Watcher:127.0.0.1:49398/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 503637 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 503637 T1361 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 503647 T1361 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 503657 T1361 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 503663 T1361 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 503671 T1361 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 503672 T1361 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 503683 T1361 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 503683 T1361 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 503692 T1361 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 503693 T1361 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 503701 T1361 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 503702 T1361 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 503720 T1361 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 503721 T1361 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 503731 T1361 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 503732 T1361 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 503744 T1361 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 503744 T1361 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 503753 T1361 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 503754 T1361 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 503762 T1361 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 503763 T1361 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 503771 T1361 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 503772 T1361 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 503780 T1361 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 503781 T1361 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> Using new style solr.xml
[junit4] 2> 504159 T1361 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 504166 T1361 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49401
[junit4] 2> 504166 T1361 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 504167 T1361 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 504167 T1361 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140
[junit4] 2> 504168 T1361 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/'
[junit4] 2> 504192 T1361 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/solr.xml
[junit4] 2> 504252 T1361 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 504253 T1361 oasc.CoreContainer.<init> New CoreContainer 1040162459
[junit4] 2> 504253 T1361 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/]
[junit4] 2> 504255 T1361 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 504255 T1361 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 504255 T1361 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 504255 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 504256 T1361 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 504256 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 504256 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 504256 T1361 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 504257 T1361 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 504260 T1361 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 504260 T1361 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 504261 T1361 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 504261 T1361 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49398/solr
[junit4] 2> 504261 T1361 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 504263 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 504267 T1381 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7be34384 name:ZooKeeperConnection Watcher:127.0.0.1:49398 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 504268 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 504276 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 504280 T1383 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50ee7d2c name:ZooKeeperConnection Watcher:127.0.0.1:49398/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 504281 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 504286 T1361 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 504296 T1361 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 504305 T1361 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 504309 T1361 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49401_
[junit4] 2> 504311 T1361 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49401_
[junit4] 2> 504321 T1361 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 504336 T1361 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 504343 T1361 oasc.Overseer.start Overseer (id=90764548431020035-127.0.0.1:49401_-n_0000000000) starting
[junit4] 2> 504352 T1361 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 504363 T1385 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 504364 T1361 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 504372 T1361 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 504377 T1361 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 504386 T1384 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 504388 T1361 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140
[junit4] 2> 504523 T1361 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/conf/
[junit4] 2> 504530 T1361 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 504532 T1361 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 504532 T1361 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 504537 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 504541 T1388 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a51987e name:ZooKeeperConnection Watcher:127.0.0.1:49398/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 504541 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 504545 T1361 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 504553 T1361 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 504873 T1361 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 504878 T1361 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49405
[junit4] 2> 504879 T1361 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 504880 T1361 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 504880 T1361 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1384957099903
[junit4] 2> 504880 T1361 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1384957099903/'
[junit4] 2> 504908 T1361 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1384957099903/solr.xml
[junit4] 2> 504982 T1361 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 504982 T1361 oasc.CoreContainer.<init> New CoreContainer 1292831942
[junit4] 2> 504982 T1361 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1384957099903/]
[junit4] 2> 504984 T1361 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 504984 T1361 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 504984 T1361 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 504984 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 504985 T1361 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 504985 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 504985 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 504986 T1361 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 504986 T1361 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 504989 T1361 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 504989 T1361 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 504990 T1361 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 504990 T1361 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49398/solr
[junit4] 2> 504990 T1361 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 504992 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 504997 T1399 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a1ab8fe name:ZooKeeperConnection Watcher:127.0.0.1:49398 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 504998 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 505008 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 505012 T1401 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@504a80fb name:ZooKeeperConnection Watcher:127.0.0.1:49398/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 505012 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 505026 T1361 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 506037 T1361 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49405_
[junit4] 2> 506040 T1361 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49405_
[junit4] 2> 506049 T1388 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 506049 T1383 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 506050 T1401 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 506061 T1361 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1384957099903
[junit4] 2> 506217 T1361 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1384957099903/conf/
[junit4] 2> 506224 T1361 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 506225 T1361 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 506225 T1361 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 506547 T1361 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 506551 T1361 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49408
[junit4] 2> 506554 T1361 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 506554 T1361 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 506554 T1361 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579
[junit4] 2> 506555 T1361 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/'
[junit4] 2> 506583 T1361 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/solr.xml
[junit4] 2> 506649 T1361 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 506650 T1361 oasc.CoreContainer.<init> New CoreContainer 1570872841
[junit4] 2> 506650 T1361 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/]
[junit4] 2> 506651 T1361 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 506652 T1361 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 506652 T1361 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 506652 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 506653 T1361 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 506653 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 506653 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 506653 T1361 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 506654 T1361 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 506657 T1361 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 506658 T1361 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 506658 T1361 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 506659 T1361 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49398/solr
[junit4] 2> 506659 T1361 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 506660 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 506665 T1413 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@135b93a8 name:ZooKeeperConnection Watcher:127.0.0.1:49398 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 506666 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 506673 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 506677 T1415 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a94797e name:ZooKeeperConnection Watcher:127.0.0.1:49398/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 506677 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 506691 T1361 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 507709 T1361 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49408_
[junit4] 2> 507715 T1361 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49408_
[junit4] 2> 507730 T1383 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 507731 T1401 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 507731 T1388 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 507733 T1415 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 507758 T1361 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579
[junit4] 2> 507896 T1361 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/conf/
[junit4] 2> 507903 T1361 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 507904 T1361 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 507904 T1361 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 508286 T1361 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 508294 T1361 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49411
[junit4] 2> 508297 T1361 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 508297 T1361 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 508298 T1361 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257
[junit4] 2> 508298 T1361 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/'
[junit4] 2> 508325 T1361 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/solr.xml
[junit4] 2> 508388 T1361 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 508388 T1361 oasc.CoreContainer.<init> New CoreContainer 1079735746
[junit4] 2> 508389 T1361 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/]
[junit4] 2> 508390 T1361 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 508390 T1361 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 508391 T1361 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 508391 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 508391 T1361 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 508392 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 508392 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 508392 T1361 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 508392 T1361 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 508396 T1361 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 508396 T1361 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 508397 T1361 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 508397 T1361 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49398/solr
[junit4] 2> 508397 T1361 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 508399 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 508403 T1427 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ef41b6e name:ZooKeeperConnection Watcher:127.0.0.1:49398 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 508404 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 508411 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 508415 T1429 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7271451a name:ZooKeeperConnection Watcher:127.0.0.1:49398/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 508415 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 508427 T1361 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 509442 T1361 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49411_
[junit4] 2> 509445 T1361 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49411_
[junit4] 2> 509454 T1415 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 509454 T1383 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 509455 T1429 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 509455 T1401 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 509455 T1388 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 509466 T1361 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257
[junit4] 2> 509558 T1361 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/conf/
[junit4] 2> 509563 T1361 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 509564 T1361 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 509564 T1361 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 509900 T1361 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 509905 T1361 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49414
[junit4] 2> 509906 T1361 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 509906 T1361 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 509907 T1361 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919
[junit4] 2> 509907 T1361 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/'
[junit4] 2> 509934 T1361 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solr.xml
[junit4] 2> 509996 T1361 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 509997 T1361 oasc.CoreContainer.<init> New CoreContainer 1641161650
[junit4] 2> 509997 T1361 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/]
[junit4] 2> 509998 T1361 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 509998 T1361 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 509999 T1361 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 510000 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 510000 T1361 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 510000 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 510001 T1361 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 510001 T1361 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 510001 T1361 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 510005 T1361 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 510005 T1361 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 510006 T1361 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 510006 T1361 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49398/solr
[junit4] 2> 510006 T1361 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 510008 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 510011 T1441 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2943d32f name:ZooKeeperConnection Watcher:127.0.0.1:49398 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 510013 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 510020 T1361 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 510025 T1443 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48cadb34 name:ZooKeeperConnection Watcher:127.0.0.1:49398/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 510025 T1361 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 510039 T1361 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 511050 T1361 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49414_
[junit4] 2> 511053 T1361 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49414_
[junit4] 2> 511067 T1415 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 511068 T1383 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 511068 T1401 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 511070 T1443 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 511071 T1388 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 511071 T1429 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 511084 T1361 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919
[junit4] 2> 511237 T1361 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/conf/
[junit4] 2> 511246 T1361 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 511247 T1361 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 511247 T1361 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 511286 T1394 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&collection.configName=conf1&name=solrj_collection&replicationFactor=2&action=CREATE&router.field=myOwnField&wt=javabin&router.name=compositeId&version=2
[junit4] 2> 511288 T1383 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 511292 T1385 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.field":"myOwnField",
[junit4] 2> "router.name":"compositeId"}
[junit4] 2> 511292 T1385 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.field":"myOwnField",
[junit4] 2> "router.name":"compositeId"}
[junit4] 2> 511932 T1384 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 511934 T1384 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
[junit4] 2> 511934 T1384 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
[junit4] 2> 511946 T1415 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 511946 T1383 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 511947 T1429 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 511947 T1401 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 511948 T1388 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 511948 T1443 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 512015 T1385 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
[junit4] 2> 512016 T1385 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:49401_
[junit4] 2> 512017 T1385 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:49411_
[junit4] 2> 512018 T1385 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:49408_
[junit4] 2> 512018 T1385 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:49414_
[junit4] 2> 512044 T1407 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
[junit4] 2> 512046 T1375 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
[junit4] 2> 512048 T1438 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
[junit4] 2> 512050 T1423 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
[junit4] 2> 512053 T1438 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 512054 T1407 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 512055 T1375 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 512055 T1423 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 513471 T1384 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 513475 T1384 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:49408",
[junit4] 2> "core":"solrj_collection_shard2_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49408_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 513491 T1384 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:49401",
[junit4] 2> "core":"solrj_collection_shard1_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49401_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 513502 T1384 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:49411",
[junit4] 2> "core":"solrj_collection_shard1_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49411_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 513512 T1384 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:49414",
[junit4] 2> "core":"solrj_collection_shard2_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49414_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 513523 T1429 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 513524 T1383 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 513523 T1415 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 513524 T1401 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 513524 T1388 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 513524 T1443 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 514058 T1423 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
[junit4] 2> 514058 T1438 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
[junit4] 2> 514062 T1423 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/solrj_collection_shard1_replica2
[junit4] 2> 514063 T1423 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 514058 T1375 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
[junit4] 2> 514058 T1407 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
[junit4] 2> 514068 T1375 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/solrj_collection_shard1_replica1
[junit4] 2> 514069 T1375 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 514063 T1438 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2
[junit4] 2> 514069 T1407 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/solrj_collection_shard2_replica1
[junit4] 2> 514071 T1407 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 514071 T1438 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 514072 T1423 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 514072 T1423 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 514073 T1375 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 514073 T1407 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 514074 T1407 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 514073 T1438 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 514075 T1438 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 514074 T1375 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 514080 T1423 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 514081 T1375 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 514081 T1438 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 514084 T1407 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 514086 T1375 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/solrj_collection_shard1_replica1/'
[junit4] 2> 514086 T1423 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/solrj_collection_shard1_replica2/'
[junit4] 2> 514087 T1407 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/solrj_collection_shard2_replica1/'
[junit4] 2> 514086 T1438 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/'
[junit4] 2> 514227 T1375 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 514228 T1423 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 514238 T1438 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 514250 T1407 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 514342 T1375 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 514346 T1375 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 514358 T1438 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 514361 T1438 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 514365 T1375 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
[junit4] 2> 514369 T1438 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
[junit4] 2> 514390 T1407 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 514400 T1407 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 514400 T1423 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 514414 T1423 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 514416 T1407 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
[junit4] 2> 514422 T1423 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
[junit4] 2> 515661 T1375 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 515675 T1375 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 515678 T1375 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 515719 T1375 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 515725 T1375 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 515738 T1375 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 515749 T1375 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 515758 T1375 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 515759 T1375 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 515768 T1438 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 515784 T1438 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 515788 T1438 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 515800 T1423 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 515812 T1423 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 515816 T1423 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 515823 T1375 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 515825 T1375 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 515825 T1375 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 515825 T1375 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/solrj_collection_shard1_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/solrj_collection_shard1_replica1/data/
[junit4] 2> 515826 T1375 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5da8f697
[junit4] 2> 515831 T1375 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/solrj_collection_shard1_replica1/data
[junit4] 2> 515835 T1375 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/solrj_collection_shard1_replica1/data/index/
[junit4] 2> 515836 T1375 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 515837 T1407 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 515837 T1375 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1384957099140/solrj_collection_shard1_replica1/data/index
[junit4] 2> 515839 T1375 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=58.4541015625, floorSegmentMB=0.431640625, forceMergeDeletesPctAllowed=4.401081985718899, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4601407303437862
[junit4] 2> 515844 T1375 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7376d798 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2d7db15e),segFN=segments_1,generation=1}
[junit4] 2> 515844 T1375 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 515848 T1407 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 515849 T1375 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 515854 T1375 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 515855 T1375 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 515855 T1375 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 515855 T1375 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 515856 T1375 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 515856 T1375 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 515856 T1375 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 515857 T1375 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 515857 T1407 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 515857 T1375 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 515858 T1375 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 515859 T1375 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 515859 T1375 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 515860 T1375 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 515860 T1375 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 515861 T1375 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 515865 T1423 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 515874 T1423 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 515875 T1438 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 515879 T1375 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 515879 T1423 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 515883 T1423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 515884 T1423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 515884 T1423 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 515888 T1375 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 515888 T1375 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 515888 T1438 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 515889 T1423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 515890 T1423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 515891 T1423 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 515892 T1423 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/solrj_collection_shard1_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/solrj_collection_shard1_replica2/data/
[junit4] 2> 515893 T1423 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5da8f697
[junit4] 2> 515889 T1375 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=91.958984375, floorSegmentMB=0.7978515625, forceMergeDeletesPctAllowed=28.434447748284953, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 515895 T1423 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/solrj_collection_shard1_replica2/data
[junit4] 2> 515896 T1423 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/solrj_collection_shard1_replica2/data/index/
[junit4] 2> 515896 T1423 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 515897 T1423 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1384957103257/solrj_collection_shard1_replica2/data/index
[junit4] 2> 515898 T1423 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=58.4541015625, floorSegmentMB=0.431640625, forceMergeDeletesPctAllowed=4.401081985718899, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4601407303437862
[junit4] 2> 515898 T1375 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7376d798 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2d7db15e),segFN=segments_1,generation=1}
[junit4] 2> 515898 T1375 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 515898 T1438 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 515899 T1375 oass.SolrIndexSearcher.<init> Opening Searcher@30a70a46 main
[junit4] 2> 515903 T1423 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@709182eb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4bcaa656),segFN=segments_1,generation=1}
[junit4] 2> 515904 T1423 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 515905 T1438 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 515905 T1438 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 515905 T1438 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 515910 T1449 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica1] Registered new searcher Searcher@30a70a46 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 515912 T1423 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 515912 T1423 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 515912 T1423 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 515912 T1375 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica1
[junit4] 2> 515913 T1375 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica1 address:http://127.0.0.1:49401 collection:solrj_collection shard:shard1
[junit4] 2> 515913 T1423 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 515914 T1438 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 515914 T1438 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 515915 T1438 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 515916 T1438 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/data/
[junit4] 2> 515916 T1438 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5da8f697
[junit4] 2> 515914 T1423 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 515917 T1423 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 515917 T1423 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 515918 T1423 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 515918 T1423 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 515918 T1423 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 515919 T1423 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 515919 T1423 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 515920 T1423 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 515920 T1423 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 515921 T1423 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 515921 T1423 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 515923 T1423 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 515926 T1438 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/data
[junit4] 2> 515928 T1423 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 515929 T1423 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 515929 T1438 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/data/index/
[junit4] 2> 515929 T1438 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 515930 T1423 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=91.958984375, floorSegmentMB=0.7978515625, forceMergeDeletesPctAllowed=28.434447748284953, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 515931 T1438 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/data/index
[junit4] 2> 515932 T1375 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
[junit4] 2> 515933 T1438 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=58.4541015625, floorSegmentMB=0.431640625, forceMergeDeletesPctAllowed=4.401081985718899, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4601407303437862
[junit4] 2> 515934 T1423 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@709182eb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4bcaa656),segFN=segments_1,generation=1}
[junit4] 2> 515937 T1423 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 515937 T1438 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1db21ac4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@24e9da81),segFN=segments_1,generation=1}
[junit4] 2> 515937 T1438 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 515940 T1407 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 515943 T1438 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 515944 T1438 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 515944 T1438 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 515945 T1438 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 515945 T1438 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 515945 T1438 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 515946 T1438 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 515946 T1438 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 515946 T1438 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 515947 T1438 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 515937 T1423 oass.SolrIndexSearcher.<init> Opening Searcher@3d29810f main
[junit4] 2> 515945 T1407 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 515952 T1438 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 515952 T1438 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 515952 T1438 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 515952 T1450 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica2] Registered new searcher Searcher@3d29810f main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 515953 T1438 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 515954 T1438 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 515955 T1438 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 515956 T1423 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica2
[junit4] 2> 515956 T1423 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica2 address:http://127.0.0.1:49411 collection:solrj_collection shard:shard1
[junit4] 2> 515957 T1438 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 515964 T1407 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 515964 T1438 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 515966 T1438 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 515966 T1423 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 515968 T1407 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 515968 T1407 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 515968 T1407 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 515969 T1438 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=91.958984375, floorSegmentMB=0.7978515625, forceMergeDeletesPctAllowed=28.434447748284953, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 515971 T1407 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 515971 T1407 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 515971 T1407 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 515972 T1407 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/solrj_collection_shard2_replica1/data/
[junit4] 2> 515972 T1407 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5da8f697
[junit4] 2> 515971 T1438 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1db21ac4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@24e9da81),segFN=segments_1,generation=1}
[junit4] 2> 515973 T1438 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 515973 T1438 oass.SolrIndexSearcher.<init> Opening Searcher@54b0581e main
[junit4] 2> 515973 T1407 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/solrj_collection_shard2_replica1/data
[junit4] 2> 515974 T1407 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/solrj_collection_shard2_replica1/data/index/
[junit4] 2> 515975 T1407 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 515976 T1407 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1384957101579/solrj_collection_shard2_replica1/data/index
[junit4] 2> 515976 T1407 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=58.4541015625, floorSegmentMB=0.431640625, forceMergeDeletesPctAllowed=4.401081985718899, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4601407303437862
[junit4] 2> 515977 T1451 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@54b0581e main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 515978 T1407 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6e1496d0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@46a4fd82),segFN=segments_1,generation=1}
[junit4] 2> 515978 T1407 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 515979 T1438 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
[junit4] 2> 515979 T1438 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:49414 collection:solrj_collection shard:shard2
[junit4] 2> 515976 T1423 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 515980 T1423 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C475 name=solrj_collection_shard1_replica2 org.apache.solr.core.SolrCore@59561cdc url=http://127.0.0.1:49411/solrj_collection_shard1_replica2 node=127.0.0.1:49411_ C475_STATE=coll:solrj_collection core:solrj_collection_shard1_replica2 props:{state=down, base_url=http://127.0.0.1:49411, core=solrj_collection_shard1_replica2, node_name=127.0.0.1:49411_}
[junit4] 2> 515980 T1423 C475 P49411 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49411/solrj_collection_shard1_replica2/
[junit4] 2> 515981 T1423 C475 P49411 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard1_replica2 url=http://127.0.0.1:49411 START replicas=[http://127.0.0.1:49401/solrj_collection_shard1_replica1/] nUpdates=100
[junit4] 2> 515983 T1407 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 515984 T1423 C475 P49411 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard1_replica2 url=http://127.0.0.1:49411 DONE. We have no versions. sync failed.
[junit4] 2> 515987 T1423 C475 P49411 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 515987 T1423 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 515987 T1423 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49411/solrj_collection_shard1_replica2/ shard1
[junit4] 2> 515987 T1423 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leaders/shard1
[junit4] 2> 515986 T1407 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 515988 T1407 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 515989 T1407 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 515989 T1407 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 515989 T1407 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 515990 T1407 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 515990 T1407 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 515990 T1407 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> ASYNC NEW_CORE C476 name=solrj_collection_shard1_replica1 org.apache.solr.core.SolrCore@5a0b1082 url=http://127.0.0.1:49401/solrj_collection_shard1_replica1 node=127.0.0.1:49401_ C476_STATE=coll:solrj_collection core:solrj_collection_shard1_replica1 props:{state=down, base_url=http://127.0.0.1:49401, core=solrj_collection_shard1_replica1, node_name=127.0.0.1:49401_}
[junit4] 2> 515992 T1379 C476 P49401 oasc.SolrCore.execute [solrj_collection_shard1_replica1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4] 2> 515992 T1407 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 515993 T1407 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 515993 T1407 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 515994 T1407 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 515994 T1407 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 515995 T1407 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 515995 T1407 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 515995 T1438 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
[junit4] 2> 515997 T1407 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 516003 T1407 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 516004 T1407 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 516005 T1407 oasu.RandomMerg
[...truncated too long message...]
"shard_parent":null,
[junit4] 2> "collection":"conf1",
[junit4] 2> "numShards":"4",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 607453 T1361 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 49414
[junit4] 2> 607453 T1361 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1641161650
[junit4] 2> 607461 T1475 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49414",
[junit4] 2> "core":"solrj_collection_shard2_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49414_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "core_node_name":"core_node4"}
[junit4] 2> 607461 T1475 oasc.Overseer$ClusterStateUpdater.updateState shard=shard2 is already registered
[junit4] 2> 607471 T1443 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> 608880 T1429 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 609459 T1361 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
[junit4] 2> 609467 T1361 oasc.SolrCore.close [solrj_collection_shard2_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@6bf43234
[junit4] 2> 609486 T1361 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 609487 T1361 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 609487 T1361 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 609488 T1361 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 609491 T1361 oasc.SolrCore.closeSearcher [solrj_collection_shard2_replica2] Closing main searcher on request.
[junit4] 2> 609491 T1361 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 609491 T1361 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/data [CachedDir<<refCount=0;path=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/data;done=false>>]
[junit4] 2> 609492 T1361 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/data
[junit4] 2> 609492 T1361 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/data/index [CachedDir<<refCount=0;path=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/data/index;done=false>>]
[junit4] 2> 609492 T1361 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1384957104919/solrj_collection_shard2_replica2/data/index
[junit4] 2> 609494 T1475 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90764548431020044-127.0.0.1:49414_-n_0000000004) am no longer a leader.
[junit4] 2> 609498 T1443 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 609513 T1361 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 609572 T1361 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 609579 T1361 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49398 49398
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=C7010678861941DD -Dtests.slow=true -Dtests.locale=el_CY -Dtests.timezone=Universal -Dtests.file.encoding=US-ASCII
[junit4] ERROR 106s | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: reloadcollection the collection time out:60s
[junit4] > at __randomizedtesting.SeedInfo.seed([C7010678861941DD:46E78860F14621E1]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:491)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:197)
[junit4] > at org.apache.solr.client.solrj.request.CollectionAdminRequest.process(CollectionAdminRequest.java:271)
[junit4] > at org.apache.solr.client.solrj.request.CollectionAdminRequest.reloadCollection(CollectionAdminRequest.java:346)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:292)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:195)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 609697 T1361 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Asserting, sim=DefaultSimilarity, locale=el_CY, timezone=Universal
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=1,free=174893368,total=300417024
[junit4] 2> NOTE: All tests run in this JVM: [BJQParserTest, TestCSVResponseWriter, TestNRTOpen, CacheHeaderTest, TestNonNRTOpen, DisMaxRequestHandlerTest, AssignTest, DeleteInactiveReplicaTest, FullSolrCloudDistribCmdsTest, ZkNodePropsTest, TestSolrQueryParserDefaultOperatorResource, TestArbitraryIndexDir, QueryFacetTest, TestSolrQueryParserResource, TestSolrCoreProperties, SolrIndexSplitterTest, TestInfoStreamLogging, IndexSchemaTest, DeleteReplicaTest, TestSolrDeletionPolicy2, TestMultiCoreConfBootstrap, TestFoldingMultitermQuery, TestTrie, TestGroupingSearch, UpdateRequestProcessorFactoryTest, PingRequestHandlerTest, PreAnalyzedUpdateProcessorTest, UpdateParamsTest, TestStressRecovery, TestExtendedDismaxParser, ClusterStateUpdateTest, TestCoreDiscovery, PolyFieldTest, CurrencyFieldXmlFileTest, TestLuceneMatchVersion, TestFunctionQuery, JSONWriterTest, AnalysisAfterCoreReloadTest, TestPostingsSolrHighlighter, DocValuesMissingTest, SpellingQueryConverterTest, DistributedDebugComponentTest, LukeRequestHandlerTest, RequiredFieldsTest, TestModifyConfFiles, TestXIncludeConfig, DefaultValueUpdateProcessorTest, TestJmxMonitoredMap, TestRangeQuery, TestSweetSpotSimilarityFactory, ReturnFieldsTest, TestJmxIntegration, DocumentBuilderTest, TestStressReorder, DateFieldTest, PathHierarchyTokenizerFactoryTest, CoreAdminHandlerTest, FileBasedSpellCheckerTest, ExternalFileFieldSortTest, TestCharFilters, TestStressUserVersions, TestPHPSerializedResponseWriter, TestWordDelimiterFilterFactory, QueryParsingTest, ShowFileRequestHandlerTest, SolrXmlInZkTest, BasicFunctionalityTest, SynonymTokenizerTest, TestRandomDVFaceting, TestSuggestSpellingConverter, TestLazyCores, TestSolr4Spatial, SpellCheckCollatorTest, SolrCoreTest, SchemaVersionSpecificBehaviorTest, CollectionsAPIDistributedZkTest]
[junit4] Completed in 106.24s, 1 test, 1 error <<< FAILURES!
[...truncated 834 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:420: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:400: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:489: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1272: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:908: There were test failures: 349 suites, 1551 tests, 1 error, 40 ignored (5 assumptions)
Total time: 83 minutes 39 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure