You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/03/09 14:17:42 UTC
[JENKINS] Lucene-Solr-NightlyTests-4.x - Build # 533 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/533/
1 tests failed.
FAILED: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testDistribSearch
Error Message:
Error executing query
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Error executing query
at __randomizedtesting.SeedInfo.seed([32BA221D4D24CC7C:B35CAC053A7BAC40]:0)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:100)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.compareResults(AbstractFullDistribZkTestBase.java:1338)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.compareResults(AbstractFullDistribZkTestBase.java:1290)
at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testIndexingBatchPerRequestWithHttpSolrServer(FullSolrCloudDistribCmdsTest.java:415)
at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.doTest(FullSolrCloudDistribCmdsTest.java:145)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:870)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:679)
Caused by: org.apache.http.ParseException: Invalid content type:
at org.apache.http.entity.ContentType.parse(ContentType.java:233)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:443)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
... 46 more
Build Log:
[...truncated 9940 lines...]
[junit4] Suite: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest
[junit4] 2> 2539367 T7764 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /s/kf
[junit4] 2> 2539371 T7764 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./solrtest-FullSolrCloudDistribCmdsTest-1394370057222
[junit4] 2> 2539372 T7764 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2539373 T7765 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2539474 T7764 oasc.ZkTestServer.run start zk server on port:35171
[junit4] 2> 2539475 T7764 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2539479 T7771 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@416c2b41 name:ZooKeeperConnection Watcher:127.0.0.1:35171 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2539479 T7764 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2539480 T7764 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2539498 T7764 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2539500 T7773 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a84de82 name:ZooKeeperConnection Watcher:127.0.0.1:35171/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2539500 T7764 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2539501 T7764 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 2539511 T7764 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 2539514 T7764 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 2539516 T7764 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 2539523 T7764 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 2539524 T7764 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 2539535 T7764 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 2539536 T7764 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 2539640 T7764 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2539641 T7764 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2539643 T7764 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 2539644 T7764 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 2539652 T7764 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 2539652 T7764 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 2539655 T7764 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 2539656 T7764 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 2539659 T7764 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 2539659 T7764 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 2539662 T7764 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 2539663 T7764 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 2539670 T7764 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2539671 T7764 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2539674 T7764 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 2539674 T7764 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 2539677 T7764 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 2539678 T7764 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 2540622 T7764 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2540626 T7764 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:26476
[junit4] 2> 2540626 T7764 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2540627 T7764 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2540627 T7764 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394370057531
[junit4] 2> 2540627 T7764 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394370057531/'
[junit4] 2> 2540652 T7764 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394370057531/solr.xml
[junit4] 2> 2540703 T7764 oasc.CoreContainer.<init> New CoreContainer 1145601087
[junit4] 2> 2540704 T7764 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394370057531/]
[junit4] 2> 2540705 T7764 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2540706 T7764 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2540706 T7764 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2540706 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2540707 T7764 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2540707 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2540707 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2540707 T7764 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2540708 T7764 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2540715 T7764 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2540716 T7764 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2540716 T7764 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2540716 T7764 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:35171/solr
[junit4] 2> 2540717 T7764 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2540717 T7764 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2540724 T7784 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72d52f1e name:ZooKeeperConnection Watcher:127.0.0.1:35171 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2540724 T7764 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2540735 T7764 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2540737 T7786 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75f783c9 name:ZooKeeperConnection Watcher:127.0.0.1:35171/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2540737 T7764 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2540739 T7764 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2540751 T7764 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2540754 T7764 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2540757 T7764 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:26476_s%2Fkf
[junit4] 2> 2540758 T7764 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:26476_s%2Fkf
[junit4] 2> 2540768 T7764 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2540770 T7764 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2540783 T7764 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:26476_s%2Fkf
[junit4] 2> 2540784 T7764 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2540786 T7764 oasc.Overseer.start Overseer (id=91381436070559747-127.0.0.1:26476_s%2Fkf-n_0000000000) starting
[junit4] 2> 2540797 T7764 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2540809 T7788 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2540809 T7764 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2540809 T7788 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 2540811 T7764 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2540820 T7764 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2540822 T7787 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2540826 T7789 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 2540826 T7789 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2540828 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2540828 T7789 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2540829 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2540829 T7787 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:26476/s/kf",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:26476_s%2Fkf",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2540829 T7787 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 2540829 T7787 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2540831 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2540841 T7786 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> 2541829 T7789 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2541829 T7789 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394370057531/collection1
[junit4] 2> 2541829 T7789 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 2541830 T7789 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2541830 T7789 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2541831 T7789 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2541832 T7789 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394370057531/collection1/'
[junit4] 2> 2541833 T7789 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394370057531/collection1/lib/.svn/' to classloader
[junit4] 2> 2541834 T7789 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394370057531/collection1/lib/README' to classloader
[junit4] 2> 2541835 T7789 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394370057531/collection1/lib/classes/' to classloader
[junit4] 2> 2541901 T7789 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 2541969 T7789 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2542070 T7789 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2542086 T7789 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2542650 T7789 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2542654 T7789 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2542656 T7789 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2542661 T7789 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2542681 T7789 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2542682 T7789 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394370057531/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/control/data/
[junit4] 2> 2542682 T7789 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@57fd54c4
[junit4] 2> 2542683 T7789 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/control/data
[junit4] 2> 2542683 T7789 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/control/data/index/
[junit4] 2> 2542683 T7789 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 2542684 T7789 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/control/data/index
[junit4] 2> 2542684 T7789 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=23, maxMergeAtOnceExplicit=32, maxMergedSegmentMB=47.4931640625, floorSegmentMB=1.5166015625, forceMergeDeletesPctAllowed=10.033247594798647, segmentsPerTier=18.0, maxCFSSegmentSizeMB=1.388671875, noCFSRatio=0.5141557612714983
[junit4] 2> 2542685 T7789 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@fc07fb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ad767),segFN=segments_1,generation=1}
[junit4] 2> 2542685 T7789 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2542689 T7789 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2542689 T7789 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2542690 T7789 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2542690 T7789 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2542690 T7789 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2542691 T7789 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2542691 T7789 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2542691 T7789 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2542692 T7789 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2542692 T7789 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2542693 T7789 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2542693 T7789 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2542693 T7789 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2542694 T7789 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2542694 T7789 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2542695 T7789 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2542705 T7789 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2542711 T7789 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2542711 T7789 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2542711 T7789 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=9, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 2542712 T7789 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@fc07fb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ad767),segFN=segments_1,generation=1}
[junit4] 2> 2542712 T7789 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2542713 T7789 oass.SolrIndexSearcher.<init> Opening Searcher@32ba9000[collection1] main
[junit4] 2> 2542716 T7790 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@32ba9000[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2542717 T7789 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2542718 T7764 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0
[junit4] 2> 2542718 T7764 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2542718 T7793 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:26476/s/kf collection:control_collection shard:shard1
[junit4] 2> 2542720 T7764 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2542720 T7793 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 2542722 T7795 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c0b3ee4 name:ZooKeeperConnection Watcher:127.0.0.1:35171/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2542722 T7764 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2542724 T7764 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2542741 T7764 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 2542742 T7793 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2542744 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2542744 T7793 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2542745 T7793 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C9390 name=collection1 org.apache.solr.core.SolrCore@78197cc3 url=http://127.0.0.1:26476/s/kf/collection1 node=127.0.0.1:26476_s%2Fkf C9390_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:26476/s/kf, core=collection1, node_name=127.0.0.1:26476_s%2Fkf}
[junit4] 2> 2542745 T7793 C9390 P26476 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:26476/s/kf/collection1/
[junit4] 2> 2542745 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2542745 T7793 C9390 P26476 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2542746 T7793 C9390 P26476 oasc.SyncStrategy.syncToMe http://127.0.0.1:26476/s/kf/collection1/ has no replicas
[junit4] 2> 2542746 T7793 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:26476/s/kf/collection1/ shard1
[junit4] 2> 2542746 T7793 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 2542748 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2542749 T7786 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> 2542749 T7795 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> 2542753 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2542756 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2542858 T7786 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> 2542858 T7795 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> 2542906 T7793 oasc.ZkController.register We are http://127.0.0.1:26476/s/kf/collection1/ and leader is http://127.0.0.1:26476/s/kf/collection1/
[junit4] 2> 2542906 T7793 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:26476/s/kf
[junit4] 2> 2542906 T7793 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2542906 T7793 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 2542906 T7793 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2542908 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2542908 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2542908 T7793 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2542908 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2542909 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2542910 T7787 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:26476/s/kf",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:26476_s%2Fkf",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 2542919 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2543021 T7786 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> 2543021 T7795 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> 2543653 T7764 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 2543654 T7764 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2543656 T7764 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:50405
[junit4] 2> 2543657 T7764 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2543657 T7764 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2543657 T7764 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394370060591
[junit4] 2> 2543658 T7764 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394370060591/'
[junit4] 2> 2543682 T7764 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394370060591/solr.xml
[junit4] 2> 2543733 T7764 oasc.CoreContainer.<init> New CoreContainer 928611822
[junit4] 2> 2543734 T7764 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394370060591/]
[junit4] 2> 2543735 T7764 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2543735 T7764 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2543735 T7764 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2543736 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2543736 T7764 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2543736 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2543737 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2543737 T7764 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2543737 T7764 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2543745 T7764 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2543745 T7764 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2543745 T7764 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2543746 T7764 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:35171/solr
[junit4] 2> 2543746 T7764 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2543747 T7764 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2543750 T7806 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@545ab0a5 name:ZooKeeperConnection Watcher:127.0.0.1:35171 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2543750 T7764 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2543762 T7764 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2543764 T7808 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d0df03b name:ZooKeeperConnection Watcher:127.0.0.1:35171/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2543764 T7764 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2543775 T7764 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2544778 T7764 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50405_s%2Fkf
[junit4] 2> 2544790 T7764 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50405_s%2Fkf
[junit4] 2> 2544793 T7786 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2544793 T7808 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2544793 T7795 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2544813 T7809 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2544813 T7809 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2544815 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2544815 T7809 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2544815 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2544815 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2544817 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2544817 T7787 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:50405/s/kf",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50405_s%2Fkf",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2544818 T7787 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 2544818 T7787 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2544827 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2544828 T7808 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> 2544828 T7795 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> 2544828 T7786 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> 2545816 T7809 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2545816 T7809 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394370060591/collection1
[junit4] 2> 2545816 T7809 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2545817 T7809 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2545817 T7809 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2545818 T7809 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2545819 T7809 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394370060591/collection1/'
[junit4] 2> 2545821 T7809 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394370060591/collection1/lib/.svn/' to classloader
[junit4] 2> 2545821 T7809 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394370060591/collection1/lib/classes/' to classloader
[junit4] 2> 2545822 T7809 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394370060591/collection1/lib/README' to classloader
[junit4] 2> 2545895 T7809 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 2545962 T7809 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2546064 T7809 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2546074 T7809 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2546639 T7809 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2546643 T7809 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2546646 T7809 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2546651 T7809 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2546671 T7809 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2546671 T7809 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394370060591/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/jetty1/
[junit4] 2> 2546671 T7809 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@57fd54c4
[junit4] 2> 2546672 T7809 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/jetty1
[junit4] 2> 2546673 T7809 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/jetty1/index/
[junit4] 2> 2546673 T7809 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 2546673 T7809 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/jetty1/index
[junit4] 2> 2546674 T7809 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=23, maxMergeAtOnceExplicit=32, maxMergedSegmentMB=47.4931640625, floorSegmentMB=1.5166015625, forceMergeDeletesPctAllowed=10.033247594798647, segmentsPerTier=18.0, maxCFSSegmentSizeMB=1.388671875, noCFSRatio=0.5141557612714983
[junit4] 2> 2546675 T7809 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@43b68b10 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26c4b347),segFN=segments_1,generation=1}
[junit4] 2> 2546675 T7809 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2546679 T7809 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2546680 T7809 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2546680 T7809 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2546680 T7809 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2546681 T7809 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2546681 T7809 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2546682 T7809 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2546682 T7809 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2546682 T7809 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2546683 T7809 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2546684 T7809 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2546684 T7809 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2546684 T7809 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2546685 T7809 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2546685 T7809 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2546686 T7809 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2546696 T7809 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2546701 T7809 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2546701 T7809 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2546702 T7809 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=9, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 2546703 T7809 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@43b68b10 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26c4b347),segFN=segments_1,generation=1}
[junit4] 2> 2546703 T7809 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2546703 T7809 oass.SolrIndexSearcher.<init> Opening Searcher@7ec555ac[collection1] main
[junit4] 2> 2546708 T7810 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7ec555ac[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2546710 T7809 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2546711 T7764 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0
[junit4] 2> 2546712 T7764 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2546711 T7813 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50405/s/kf collection:collection1 shard:shard1
[junit4] 2> 2546713 T7813 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2546734 T7813 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2546745 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2546745 T7813 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2546745 T7813 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C9391 name=collection1 org.apache.solr.core.SolrCore@649cb4b7 url=http://127.0.0.1:50405/s/kf/collection1 node=127.0.0.1:50405_s%2Fkf C9391_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:50405/s/kf, core=collection1, node_name=127.0.0.1:50405_s%2Fkf}
[junit4] 2> 2546746 T7813 C9391 P50405 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50405/s/kf/collection1/
[junit4] 2> 2546746 T7813 C9391 P50405 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2546746 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2546746 T7813 C9391 P50405 oasc.SyncStrategy.syncToMe http://127.0.0.1:50405/s/kf/collection1/ has no replicas
[junit4] 2> 2546747 T7813 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50405/s/kf/collection1/ shard1
[junit4] 2> 2546747 T7813 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2546757 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2546758 T7808 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> 2546758 T7795 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> 2546758 T7786 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> 2546769 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2546771 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2546874 T7808 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> 2546874 T7786 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> 2546874 T7795 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> 2546921 T7813 oasc.ZkController.register We are http://127.0.0.1:50405/s/kf/collection1/ and leader is http://127.0.0.1:50405/s/kf/collection1/
[junit4] 2> 2546921 T7813 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50405/s/kf
[junit4] 2> 2546921 T7813 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2546921 T7813 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 2546921 T7813 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2546923 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2546923 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2546923 T7813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2546923 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2546925 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2546925 T7787 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:50405/s/kf",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50405_s%2Fkf",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 2546934 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2547036 T7786 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> 2547036 T7795 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> 2547036 T7808 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> 2547705 T7764 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 2547706 T7764 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2547709 T7764 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:57067
[junit4] 2> 2547709 T7764 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2547710 T7764 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2547710 T7764 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394370064562
[junit4] 2> 2547711 T7764 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394370064562/'
[junit4] 2> 2547747 T7764 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394370064562/solr.xml
[junit4] 2> 2547825 T7764 oasc.CoreContainer.<init> New CoreContainer 2143621529
[junit4] 2> 2547826 T7764 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394370064562/]
[junit4] 2> 2547828 T7764 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2547828 T7764 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2547829 T7764 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2547829 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2547830 T7764 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2547830 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2547831 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2547831 T7764 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2547832 T7764 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2547843 T7764 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2547843 T7764 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2547844 T7764 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2547845 T7764 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:35171/solr
[junit4] 2> 2547845 T7764 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2547846 T7764 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2547849 T7824 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63069557 name:ZooKeeperConnection Watcher:127.0.0.1:35171 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2547849 T7764 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2547862 T7764 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2547864 T7826 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fd4d92b name:ZooKeeperConnection Watcher:127.0.0.1:35171/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2547864 T7764 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2547879 T7764 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2548882 T7764 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57067_s%2Fkf
[junit4] 2> 2548893 T7764 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57067_s%2Fkf
[junit4] 2> 2548895 T7795 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2548896 T7786 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2548896 T7826 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2548896 T7808 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2548920 T7827 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2548920 T7827 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2548921 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2548921 T7827 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2548921 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2548922 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2548923 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2548924 T7787 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:57067/s/kf",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57067_s%2Fkf",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2548924 T7787 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2548924 T7787 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2548928 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2548937 T7808 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> 2548937 T7786 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> 2548937 T7795 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> 2548937 T7826 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> 2549923 T7827 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2549923 T7827 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394370064562/collection1
[junit4] 2> 2549923 T7827 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2549924 T7827 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2549924 T7827 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2549925 T7827 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2549925 T7827 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394370064562/collection1/'
[junit4] 2> 2549927 T7827 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394370064562/collection1/lib/README' to classloader
[junit4] 2> 2549927 T7827 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394370064562/collection1/lib/classes/' to classloader
[junit4] 2> 2549928 T7827 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394370064562/collection1/lib/.svn/' to classloader
[junit4] 2> 2549995 T7827 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 2550063 T7827 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2550164 T7827 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2550175 T7827 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2550752 T7827 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2550756 T7827 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2550759 T7827 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2550764 T7827 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2550784 T7827 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2550784 T7827 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394370064562/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/jetty2/
[junit4] 2> 2550784 T7827 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@57fd54c4
[junit4] 2> 2550785 T7827 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/jetty2
[junit4] 2> 2550786 T7827 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/jetty2/index/
[junit4] 2> 2550786 T7827 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 2550786 T7827 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394370057221/jetty2/index
[junit4] 2> 2550787 T7827 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=23, maxMergeAtOnceExplicit=32, maxMergedSegmentMB=47.4931640625, floorSegmentMB=1.5166015625, forceMergeDeletesPctAllowed=10.033247594798647, segmentsPerTier=18.0, maxCFSSegmentSizeMB=1.388671875, noCFSRatio=0.5141557612714983
[junit4] 2> 2550788 T7827 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@fdf2a69 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@21b6a54d),segFN=segments_1,generation=1}
[junit4] 2> 2550788 T7827 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2550792 T7827 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2550793 T7827 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2550793 T7827 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2550793 T7827 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2550794 T7827 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2550794 T7827 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2550794 T7827 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2550795 T7827 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2550795 T7827 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2550796 T7827 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2550796 T7827 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2550797 T7827 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2550797 T7827 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2550798 T7827 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2550798 T7827 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2550799 T7827 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2550808 T7827 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2550814 T7827 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2550814 T7827 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2550815 T7827 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=9, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 2550815 T7827 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@fdf2a69 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@21b6a54d),segFN=segments_1,generation=1}
[junit4] 2> 2550816 T7827 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2550816 T7827 oass.SolrIndexSearcher.<init> Opening Searcher@2eb00af5[collection1] main
[junit4] 2> 2550820 T7828 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2eb00af5[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2550823 T7827 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2550824 T7764 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0
[junit4] 2> 2550824 T7764 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2550824 T7831 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57067/s/kf collection:collection1 shard:shard2
[junit4] 2> 2550826 T7831 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2550844 T7831 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 2550855 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2550856 T7831 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2550856 T7831 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C9392 name=collection1 org.apache.solr.core.SolrCore@73b57d25 url=http://127.0.0.1:57067/s/kf/collection1 node=127.0.0.1:57067_s%2Fkf C9392_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:57067/s/kf, core=collection1, node_name=127.0.0.1:57067_s%2Fkf}
[junit4] 2> 2550857 T7831 C9392 P57067 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57067/s/kf/collection1/
[junit4] 2> 2550857 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2550857 T7831 C9392 P57067 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2550857 T7831 C9392 P57067 oasc.SyncStrategy.syncToMe http://127.0.0.1:57067/s/kf/collection1/ has no replicas
[junit4] 2> 2550858 T7831 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57067/s/kf/collection1/ shard2
[junit4] 2> 2550858 T7831 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2550860 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2550869 T7808 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> 2550869 T7826 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> 2550869 T7786 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> 2550869 T7795 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> 2550880 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2550883 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2550986 T7808 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> 2550986 T7826 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> 2550986 T7786 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> 2550986 T7795 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> 2551032 T7831 oasc.ZkController.register We are http://127.0.0.1:57067/s/kf/collection1/ and leader is http://127.0.0.1:57067/s/kf/collection1/
[junit4] 2> 2551032 T7831 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57067/s/kf
[junit4] 2> 2551032 T7831 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2551032 T7831 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 2551032 T7831 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2551034 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2551034 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2551034 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2551034 T7831 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2551035 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2551036 T7787 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:57067/s/kf",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57067_s%2Fkf",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 2551045 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2551174 T7795 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> 2551174 T7786 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> 2551174 T7826 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> 2551174 T7808 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> 2551714 T7764 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 2551715 T7764 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2551717 T7764 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:16437
[junit4] 2> 2551718 T7764 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2551718 T7764 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2551719 T7764 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394370068675
[junit4] 2> 2551719 T7764 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394370068675/'
[junit4] 2> 2551743 T7764 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394370068675/solr.xml
[junit4] 2> 2551795 T7764 oasc.CoreContainer.<init> New CoreContainer 1965454670
[junit4] 2> 2551796 T7764 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394370068675/]
[junit4] 2> 2551797 T7764 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2551797 T7764 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2551797 T7764 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2551798 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2551798 T7764 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2551798 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2551799 T7764 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2551799 T7764 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2551799 T7764 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2551807 T7764 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2551807 T7764 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2551807 T7764 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2551808 T7764 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:35171/solr
[junit4] 2> 2551808 T7764 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2551809 T7764 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2551839 T7842 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2fdf8ff8 name:ZooKeeperConnection Watcher:127.0.0.1:35171 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2551839 T7764 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2551842 T7764 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2551844 T7844 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15386e7f name:ZooKeeperConnection Watcher:127.0.0.1:35171/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2551844 T7764 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2551856 T7764 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2552859 T7764 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:16437_s%2Fkf
[junit4] 2> 2552871 T7764 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:16437_s%2Fkf
[junit4] 2> 2552874 T7795 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2552875 T7786 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2552875 T7844 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2552874 T7826 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2552874 T7808 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2552893 T7845 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2552894 T7845 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2552895 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2552895 T7845 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2552895 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2552896 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2552896 T7787 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2552897 T7787 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:16437/s/kf",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:16437_s%2Fkf",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2552897 T7787 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2552898 T7787 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2552906 T7786 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2552908 T7808 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> 2552908 T7786 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> 2552908 T7844 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> 2552908 T7826 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> 2552908 T7795 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> 2553897 T7845 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2553897 T7845 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394370068675/collection1
[junit4] 2> 2553897 T7845 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2553898 T7845 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2553898 T7845 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2553899 T7845 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2553900 T7845 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394370068675/collection1/'
[junit4] 2> 2553902 T7845 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394370068675/collection1/lib/classes/' to classloader
[junit4] 2> 2553902 T784
[...truncated too long message...]
actory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2666251 T7901 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty6-1394370080956/collection2_shard3_replica3/data [CachedDir<<refCount=0;path=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty6-1394370080956/collection2_shard3_replica3/data;done=false>>]
[junit4] 2> 2666251 T7901 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty6-1394370080956/collection2_shard3_replica3/data
[junit4] 2> 2666251 T7901 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty6-1394370080956/collection2_shard3_replica3/data/index [CachedDir<<refCount=0;path=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty6-1394370080956/collection2_shard3_replica3/data/index;done=false>>]
[junit4] 2> 2666251 T7901 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty6-1394370080956/collection2_shard3_replica3/data/index
[junit4] 2> 2666252 T7901 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection2/leader_elect/shard5/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 2666252 T7901 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection2/leader_elect/shard2/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 2666253 T7901 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 2666253 T7901 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene3x, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=lv_LV, timezone=Etc/GMT-14
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=1,free=123140960,total=477233152
[junit4] 2> NOTE: All tests run in this JVM: [TestInfoStreamLogging, TestPseudoReturnFields, SearchHandlerTest, EnumFieldTest, TestCoreContainer, HdfsDirectoryTest, RegexBoostProcessorTest, TestSurroundQueryParser, TriLevelCompositeIdRoutingTest, SuggesterTest, TestLuceneMatchVersion, DistributedSuggestComponentTest, SynonymTokenizerTest, TestElisionMultitermQuery, TestExpandComponent, SampleTest, LukeRequestHandlerTest, ExternalFileFieldSortTest, TestConfig, SOLR749Test, TestSolrIndexConfig, DateMathParserTest, TestMaxScoreQueryParser, BJQParserTest, MBeansHandlerTest, TestStressVersions, QueryEqualityTest, TestSuggestSpellingConverter, CoreAdminHandlerTest, JsonLoaderTest, DeleteShardTest, TestDefaultSearchFieldResource, LegacyHTMLStripCharFilterTest, ShardRoutingTest, AnalysisErrorHandlingTest, TermsComponentTest, TestMergePolicyConfig, RemoteQueryErrorTest, QueryElevationComponentTest, TestRandomDVFaceting, TestClassNameShortening, TestNoOpRegenerator, TestQueryUtils, ZkControllerTest, ReturnFieldsTest, TestExtendedDismaxParser, TestGroupingSearch, TestBadConfig, CustomCollectionTest, TestSearchPerf, TestSchemaVersionResource, DocValuesTest, TestHighFrequencyDictionaryFactory, UnloadDistributedZkTest, BlockCacheTest, UpdateParamsTest, PeerSyncTest, TestPerFieldSimilarity, BinaryUpdateRequestHandlerTest, SuggestComponentTest, PrimitiveFieldTypeTest, TestLMJelinekMercerSimilarityFactory, AnalysisAfterCoreReloadTest, TestManagedSchema, SuggesterFSTTest, TestCursorMarkWithoutUniqueKey, SystemInfoHandlerTest, SimpleFacetsTest, DOMUtilTest, TestReplicationHandler, TestJoin, TestFieldSortValues, OverseerRolesTest, ZkCLITest, MigrateRouteKeyTest, OverseerCollectionProcessorTest, TestSolrXmlPersistor, SolrXmlInZkTest, HdfsBasicDistributedZkTest, HdfsChaosMonkeySafeLeaderTest, OverseerTest, WordBreakSolrSpellCheckerTest, DistributedTermsComponentTest, ScriptEngineTest, TestCustomSort, RecoveryZkTest, TestLRUCache, TestCharFilters, TestValueSourceCache, OpenCloseCoreStressTest, BasicZkTest, FullSolrCloudDistribCmdsTest]
[junit4] Completed on J0 in 127.86s, 1 test, 1 error <<< FAILURES!
[...truncated 562 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:478: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:451: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/common-build.xml:490: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1278: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:911: There were test failures: 369 suites, 1578 tests, 1 error, 35 ignored (6 assumptions)
Total time: 177 minutes 24 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-NightlyTests-4.x - Build # 534 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/534/
2 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.FullSolrCloudDistribCmdsTest
Error Message:
Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=6502, name=qtp1299495378-6502, state=RUNNABLE, group=TGRP-FullSolrCloudDistribCmdsTest], registration stack trace below.
Stack Trace:
com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=6502, name=qtp1299495378-6502, state=RUNNABLE, group=TGRP-FullSolrCloudDistribCmdsTest], registration stack trace below.
at __randomizedtesting.SeedInfo.seed([BC0D37B7253679CB]:0)
at java.lang.Thread.getStackTrace(Thread.java:1495)
at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:555)
at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:1054)
at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:946)
at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:938)
at org.apache.solr.core.MockDirectoryFactory.create(MockDirectoryFactory.java:37)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:350)
at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:257)
at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:471)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:762)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:631)
at org.apache.solr.core.ZkContainer.createFromZk(ZkContainer.java:245)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:595)
at org.apache.solr.handler.admin.CoreAdminHandler.handleCreateAction(CoreAdminHandler.java:518)
at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:153)
at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
at org.apache.solr.servlet.SolrDispatchFilter.handleAdminRequest(SolrDispatchFilter.java:732)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:268)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:217)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419)
at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:134)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
at org.eclipse.jetty.server.handler.GzipHandler.handle(GzipHandler.java:301)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1077)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:384)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1009)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
at org.eclipse.jetty.server.Server.handle(Server.java:368)
at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:489)
at org.eclipse.jetty.server.BlockingHttpConnection.handleRequest(BlockingHttpConnection.java:53)
at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:953)
at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:1014)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:861)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:72)
at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:264)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
at java.lang.Thread.run(Thread.java:679)
Caused by: java.lang.AssertionError: Directory not closed: MockDirectoryWrapper(RAMDirectory@58964d3a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3837798f)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.lucene.util.CloseableDirectory.close(CloseableDirectory.java:47)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:602)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:599)
at com.carrotsearch.randomizedtesting.RandomizedContext.closeResources(RandomizedContext.java:167)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2.afterAlways(RandomizedRunner.java:615)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
... 1 more
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload
Error Message:
expected:<[{indexVersion=1394483743619,generation=2,filelist=[_1.fdt, _1.fdx, _1.fnm, _1.nvd, _1.nvm, _1.si, _1_MockVariableIntBlock_0.doc, _1_MockVariableIntBlock_0.skp, _1_MockVariableIntBlock_0.tib, _1_MockVariableIntBlock_0.tii, _2.fdt, _2.fdx, _2.fnm, _2.nvd, _2.nvm, _2.si, _2_MockVariableIntBlock_0.doc, _2_MockVariableIntBlock_0.skp, _2_MockVariableIntBlock_0.tib, _2_MockVariableIntBlock_0.tii, _5.fdt, _5.fdx, _5.fnm, _5.nvd, _5.nvm, _5.si, _5_MockVariableIntBlock_0.doc, _5_MockVariableIntBlock_0.skp, _5_MockVariableIntBlock_0.tib, _5_MockVariableIntBlock_0.tii, _6.fdt, _6.fdx, _6.fnm, _6.nvd, _6.nvm, _6.si, _6_MockVariableIntBlock_0.doc, _6_MockVariableIntBlock_0.skp, _6_MockVariableIntBlock_0.tib, _6_MockVariableIntBlock_0.tii, segments_2]}]> but was:<[{indexVersion=1394483743619,generation=2,filelist=[_1.fdt, _1.fdx, _1.fnm, _1.nvd, _1.nvm, _1.si, _1_MockVariableIntBlock_0.doc, _1_MockVariableIntBlock_0.skp, _1_MockVariableIntBlock_0.tib, _1_MockVariableIntBlock_0.tii, _2.fdt, _2.fdx, _2.fnm, _2.nvd, _2.nvm, _2.si, _2_MockVariableIntBlock_0.doc, _2_MockVariableIntBlock_0.skp, _2_MockVariableIntBlock_0.tib, _2_MockVariableIntBlock_0.tii, _5.fdt, _5.fdx, _5.fnm, _5.nvd, _5.nvm, _5.si, _5_MockVariableIntBlock_0.doc, _5_MockVariableIntBlock_0.skp, _5_MockVariableIntBlock_0.tib, _5_MockVariableIntBlock_0.tii, _6.fdt, _6.fdx, _6.fnm, _6.nvd, _6.nvm, _6.si, _6_MockVariableIntBlock_0.doc, _6_MockVariableIntBlock_0.skp, _6_MockVariableIntBlock_0.tib, _6_MockVariableIntBlock_0.tii, segments_2]}, {indexVersion=1394483743619,generation=3,filelist=[_1.fdt, _1.fdx, _1.fnm, _1.nvd, _1.nvm, _1.si, _1_MockVariableIntBlock_0.doc, _1_MockVariableIntBlock_0.skp, _1_MockVariableIntBlock_0.tib, _1_MockVariableIntBlock_0.tii, _2.fdt, _2.fdx, _2.fnm, _2.nvd, _2.nvm, _2.si, _2_MockVariableIntBlock_0.doc, _2_MockVariableIntBlock_0.skp, _2_MockVariableIntBlock_0.tib, _2_MockVariableIntBlock_0.tii, _5.fdt, _5.fdx, _5.fnm, _5.nvd, _5.nvm, _5.si, _5_MockVariableIntBlock_0.doc, _5_MockVariableIntBlock_0.skp, _5_MockVariableIntBlock_0.tib, _5_MockVariableIntBlock_0.tii, _7.cfe, _7.cfs, _7.si, segments_3]}]>
Stack Trace:
java.lang.AssertionError: expected:<[{indexVersion=1394483743619,generation=2,filelist=[_1.fdt, _1.fdx, _1.fnm, _1.nvd, _1.nvm, _1.si, _1_MockVariableIntBlock_0.doc, _1_MockVariableIntBlock_0.skp, _1_MockVariableIntBlock_0.tib, _1_MockVariableIntBlock_0.tii, _2.fdt, _2.fdx, _2.fnm, _2.nvd, _2.nvm, _2.si, _2_MockVariableIntBlock_0.doc, _2_MockVariableIntBlock_0.skp, _2_MockVariableIntBlock_0.tib, _2_MockVariableIntBlock_0.tii, _5.fdt, _5.fdx, _5.fnm, _5.nvd, _5.nvm, _5.si, _5_MockVariableIntBlock_0.doc, _5_MockVariableIntBlock_0.skp, _5_MockVariableIntBlock_0.tib, _5_MockVariableIntBlock_0.tii, _6.fdt, _6.fdx, _6.fnm, _6.nvd, _6.nvm, _6.si, _6_MockVariableIntBlock_0.doc, _6_MockVariableIntBlock_0.skp, _6_MockVariableIntBlock_0.tib, _6_MockVariableIntBlock_0.tii, segments_2]}]> but was:<[{indexVersion=1394483743619,generation=2,filelist=[_1.fdt, _1.fdx, _1.fnm, _1.nvd, _1.nvm, _1.si, _1_MockVariableIntBlock_0.doc, _1_MockVariableIntBlock_0.skp, _1_MockVariableIntBlock_0.tib, _1_MockVariableIntBlock_0.tii, _2.fdt, _2.fdx, _2.fnm, _2.nvd, _2.nvm, _2.si, _2_MockVariableIntBlock_0.doc, _2_MockVariableIntBlock_0.skp, _2_MockVariableIntBlock_0.tib, _2_MockVariableIntBlock_0.tii, _5.fdt, _5.fdx, _5.fnm, _5.nvd, _5.nvm, _5.si, _5_MockVariableIntBlock_0.doc, _5_MockVariableIntBlock_0.skp, _5_MockVariableIntBlock_0.tib, _5_MockVariableIntBlock_0.tii, _6.fdt, _6.fdx, _6.fnm, _6.nvd, _6.nvm, _6.si, _6_MockVariableIntBlock_0.doc, _6_MockVariableIntBlock_0.skp, _6_MockVariableIntBlock_0.tib, _6_MockVariableIntBlock_0.tii, segments_2]}, {indexVersion=1394483743619,generation=3,filelist=[_1.fdt, _1.fdx, _1.fnm, _1.nvd, _1.nvm, _1.si, _1_MockVariableIntBlock_0.doc, _1_MockVariableIntBlock_0.skp, _1_MockVariableIntBlock_0.tib, _1_MockVariableIntBlock_0.tii, _2.fdt, _2.fdx, _2.fnm, _2.nvd, _2.nvm, _2.si, _2_MockVariableIntBlock_0.doc, _2_MockVariableIntBlock_0.skp, _2_MockVariableIntBlock_0.tib, _2_MockVariableIntBlock_0.tii, _5.fdt, _5.fdx, _5.fnm, _5.nvd, _5.nvm, _5.si, _5_MockVariableIntBlock_0.doc, _5_MockVariableIntBlock_0.skp, _5_MockVariableIntBlock_0.tib, _5_MockVariableIntBlock_0.tii, _7.cfe, _7.cfs, _7.si, segments_3]}]>
at __randomizedtesting.SeedInfo.seed([BC0D37B7253679CB:99DA2C87557E77C8]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:147)
at org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload(TestReplicationHandler.java:1184)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:679)
Build Log:
[...truncated 10020 lines...]
[junit4] Suite: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest
[junit4] 2> 1903200 T6240 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 1903205 T6240 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./solrtest-FullSolrCloudDistribCmdsTest-1394482963254
[junit4] 2> 1903206 T6240 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1903207 T6241 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1903308 T6240 oasc.ZkTestServer.run start zk server on port:32338
[junit4] 2> 1903309 T6240 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1903313 T6247 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5aca1495 name:ZooKeeperConnection Watcher:127.0.0.1:32338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1903313 T6240 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1903314 T6240 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1903318 T6240 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1903320 T6249 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@134012a5 name:ZooKeeperConnection Watcher:127.0.0.1:32338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1903321 T6240 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1903321 T6240 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1903335 T6240 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1903338 T6240 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1903346 T6240 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1903349 T6240 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1903350 T6240 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1903362 T6240 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 1903362 T6240 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1903466 T6240 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1903466 T6240 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1903469 T6240 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1903470 T6240 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1903473 T6240 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1903474 T6240 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1903476 T6240 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1903477 T6240 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1903480 T6240 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1903480 T6240 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1903483 T6240 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1903484 T6240 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1903491 T6240 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1903492 T6240 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1903495 T6240 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1903495 T6240 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1903498 T6240 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1903499 T6240 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1904430 T6240 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1904433 T6240 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:55486
[junit4] 2> 1904434 T6240 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1904434 T6240 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1904434 T6240 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394482963557
[junit4] 2> 1904435 T6240 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394482963557/'
[junit4] 2> 1904460 T6240 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394482963557/solr.xml
[junit4] 2> 1904511 T6240 oasc.CoreContainer.<init> New CoreContainer 249535377
[junit4] 2> 1904512 T6240 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394482963557/]
[junit4] 2> 1904513 T6240 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1904513 T6240 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1904514 T6240 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1904514 T6240 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1904514 T6240 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1904515 T6240 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1904515 T6240 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1904515 T6240 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1904515 T6240 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1904523 T6240 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1904523 T6240 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1904524 T6240 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1904524 T6240 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32338/solr
[junit4] 2> 1904524 T6240 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1904525 T6240 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1904528 T6260 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a5e5437 name:ZooKeeperConnection Watcher:127.0.0.1:32338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1904528 T6240 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1904543 T6240 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1904545 T6262 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@157b003d name:ZooKeeperConnection Watcher:127.0.0.1:32338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1904545 T6240 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1904547 T6240 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1904551 T6240 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1904554 T6240 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1904556 T6240 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55486_
[junit4] 2> 1904565 T6240 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55486_
[junit4] 2> 1904568 T6240 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1904571 T6240 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1904584 T6240 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55486_
[junit4] 2> 1904584 T6240 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1904586 T6240 oasc.Overseer.start Overseer (id=91388835480272899-127.0.0.1:55486_-n_0000000000) starting
[junit4] 2> 1904590 T6240 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1904603 T6264 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1904603 T6240 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1904603 T6264 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1904605 T6240 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1904607 T6240 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1904609 T6263 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1904613 T6265 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 1904614 T6265 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1904615 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1904615 T6265 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1904616 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1904616 T6263 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:55486",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55486_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1904616 T6263 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1904616 T6263 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1904618 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1904619 T6262 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> 1905616 T6265 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1905616 T6265 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394482963557/collection1
[junit4] 2> 1905616 T6265 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1905617 T6265 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1905618 T6265 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1905618 T6265 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1905619 T6265 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394482963557/collection1/'
[junit4] 2> 1905620 T6265 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394482963557/collection1/lib/README' to classloader
[junit4] 2> 1905621 T6265 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394482963557/collection1/lib/.svn/' to classloader
[junit4] 2> 1905621 T6265 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394482963557/collection1/lib/classes/' to classloader
[junit4] 2> 1905695 T6265 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1905783 T6265 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1905884 T6265 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1905894 T6265 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1906463 T6265 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1906467 T6265 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1906469 T6265 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1906474 T6265 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1906494 T6265 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1906495 T6265 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1394482963557/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/control/data/
[junit4] 2> 1906495 T6265 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a281902
[junit4] 2> 1906496 T6265 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/control/data
[junit4] 2> 1906496 T6265 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/control/data/index/
[junit4] 2> 1906497 T6265 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1906498 T6265 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/control/data/index
[junit4] 2> 1906498 T6265 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=91.5283203125, floorSegmentMB=0.7900390625, forceMergeDeletesPctAllowed=3.936165082632337, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6819702640925855
[junit4] 2> 1906504 T6265 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/index4169841776tmp lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5f5f3ae0),segFN=segments_1,generation=1}
[junit4] 2> 1906504 T6265 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1906507 T6265 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1906508 T6265 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1906508 T6265 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1906509 T6265 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1906509 T6265 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1906509 T6265 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1906510 T6265 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1906510 T6265 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1906510 T6265 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1906511 T6265 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1906511 T6265 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1906512 T6265 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1906512 T6265 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1906512 T6265 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1906513 T6265 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1906513 T6265 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1906523 T6265 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1906529 T6265 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1906529 T6265 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1906530 T6265 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=54.072265625, floorSegmentMB=2.0537109375, forceMergeDeletesPctAllowed=18.146429153176, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7297550961684556
[junit4] 2> 1906532 T6265 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/index4169841776tmp lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5f5f3ae0),segFN=segments_1,generation=1}
[junit4] 2> 1906532 T6265 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1906532 T6265 oass.SolrIndexSearcher.<init> Opening Searcher@33bafc6[collection1] main
[junit4] 2> 1906535 T6266 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@33bafc6[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1906537 T6265 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1906538 T6240 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0
[junit4] 2> 1906538 T6240 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1906538 T6269 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55486 collection:control_collection shard:shard1
[junit4] 2> 1906540 T6240 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1906540 T6269 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1906542 T6271 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4199aeb8 name:ZooKeeperConnection Watcher:127.0.0.1:32338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1906542 T6240 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1906553 T6240 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1906562 T6240 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1906563 T6269 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1906574 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1906574 T6269 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1906574 T6269 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1060 name=collection1 org.apache.solr.core.SolrCore@3b2bb3f url=http://127.0.0.1:55486/collection1 node=127.0.0.1:55486_ C1060_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:55486, core=collection1, node_name=127.0.0.1:55486_}
[junit4] 2> 1906575 T6269 C1060 P55486 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55486/collection1/
[junit4] 2> 1906575 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1906575 T6269 C1060 P55486 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1906575 T6269 C1060 P55486 oasc.SyncStrategy.syncToMe http://127.0.0.1:55486/collection1/ has no replicas
[junit4] 2> 1906576 T6269 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55486/collection1/ shard1
[junit4] 2> 1906576 T6269 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1906578 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1906589 T6262 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> 1906589 T6271 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> 1906601 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1906614 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1906718 T6262 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> 1906718 T6271 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> 1906754 T6269 oasc.ZkController.register We are http://127.0.0.1:55486/collection1/ and leader is http://127.0.0.1:55486/collection1/
[junit4] 2> 1906754 T6269 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55486
[junit4] 2> 1906754 T6269 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1906754 T6269 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 1906754 T6269 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1906783 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1906784 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1906784 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1906784 T6269 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1906785 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1906786 T6263 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:55486",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55486_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1906796 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1906901 T6271 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> 1906901 T6262 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> 1907450 T6240 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 1907450 T6240 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1907453 T6240 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:51226
[junit4] 2> 1907453 T6240 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1907454 T6240 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1907454 T6240 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394482966610
[junit4] 2> 1907454 T6240 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394482966610/'
[junit4] 2> 1907479 T6240 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394482966610/solr.xml
[junit4] 2> 1907530 T6240 oasc.CoreContainer.<init> New CoreContainer 1192589556
[junit4] 2> 1907531 T6240 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394482966610/]
[junit4] 2> 1907532 T6240 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1907532 T6240 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1907533 T6240 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1907533 T6240 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1907533 T6240 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1907534 T6240 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1907534 T6240 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1907534 T6240 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1907535 T6240 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1907542 T6240 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1907542 T6240 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1907542 T6240 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1907543 T6240 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32338/solr
[junit4] 2> 1907543 T6240 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1907544 T6240 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1907572 T6282 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52b7ffa1 name:ZooKeeperConnection Watcher:127.0.0.1:32338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1907573 T6240 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1907580 T6240 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1907582 T6284 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@621a3dbd name:ZooKeeperConnection Watcher:127.0.0.1:32338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1907582 T6240 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1907595 T6240 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1908598 T6240 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51226_
[junit4] 2> 1908609 T6240 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51226_
[junit4] 2> 1908612 T6262 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1908612 T6284 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1908612 T6271 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1908621 T6285 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 1908621 T6285 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1908622 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1908622 T6285 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1908622 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1908623 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1908624 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1908625 T6263 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:51226",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51226_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1908625 T6263 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1908625 T6263 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1908628 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1908638 T6271 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> 1908638 T6262 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> 1908638 T6284 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> 1909624 T6285 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1909624 T6285 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394482966610/collection1
[junit4] 2> 1909624 T6285 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1909625 T6285 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1909625 T6285 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1909626 T6285 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1909626 T6285 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394482966610/collection1/'
[junit4] 2> 1909628 T6285 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394482966610/collection1/lib/classes/' to classloader
[junit4] 2> 1909628 T6285 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394482966610/collection1/lib/.svn/' to classloader
[junit4] 2> 1909629 T6285 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394482966610/collection1/lib/README' to classloader
[junit4] 2> 1909697 T6285 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1909765 T6285 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1909866 T6285 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1909876 T6285 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1910449 T6285 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1910454 T6285 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1910456 T6285 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1910461 T6285 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1910481 T6285 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1910482 T6285 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1394482966610/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/jetty1/
[junit4] 2> 1910482 T6285 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a281902
[junit4] 2> 1910483 T6285 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/jetty1
[junit4] 2> 1910483 T6285 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/jetty1/index/
[junit4] 2> 1910483 T6285 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1910485 T6285 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/jetty1/index
[junit4] 2> 1910486 T6285 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=91.5283203125, floorSegmentMB=0.7900390625, forceMergeDeletesPctAllowed=3.936165082632337, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6819702640925855
[junit4] 2> 1910490 T6285 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/index4169841777tmp lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26b30e9a),segFN=segments_1,generation=1}
[junit4] 2> 1910490 T6285 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1910494 T6285 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1910495 T6285 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1910495 T6285 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1910495 T6285 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1910496 T6285 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1910496 T6285 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1910496 T6285 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1910497 T6285 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1910497 T6285 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1910498 T6285 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1910498 T6285 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1910499 T6285 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1910499 T6285 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1910500 T6285 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1910500 T6285 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1910501 T6285 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1910510 T6285 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1910515 T6285 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1910516 T6285 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1910516 T6285 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=54.072265625, floorSegmentMB=2.0537109375, forceMergeDeletesPctAllowed=18.146429153176, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7297550961684556
[junit4] 2> 1910518 T6285 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/index4169841777tmp lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26b30e9a),segFN=segments_1,generation=1}
[junit4] 2> 1910518 T6285 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1910519 T6285 oass.SolrIndexSearcher.<init> Opening Searcher@69df23f7[collection1] main
[junit4] 2> 1910523 T6286 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@69df23f7[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1910526 T6285 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1910526 T6240 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0
[junit4] 2> 1910527 T6240 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1910527 T6289 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51226 collection:collection1 shard:shard1
[junit4] 2> 1910529 T6289 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1910547 T6289 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1910555 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1910556 T6289 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1910556 T6289 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1061 name=collection1 org.apache.solr.core.SolrCore@1c5156e8 url=http://127.0.0.1:51226/collection1 node=127.0.0.1:51226_ C1061_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:51226, core=collection1, node_name=127.0.0.1:51226_}
[junit4] 2> 1910556 T6289 C1061 P51226 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51226/collection1/
[junit4] 2> 1910556 T6289 C1061 P51226 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1910556 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1910557 T6289 C1061 P51226 oasc.SyncStrategy.syncToMe http://127.0.0.1:51226/collection1/ has no replicas
[junit4] 2> 1910557 T6289 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51226/collection1/ shard1
[junit4] 2> 1910557 T6289 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1910560 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1910571 T6262 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> 1910571 T6271 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> 1910571 T6284 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> 1910697 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1910698 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1910718 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1910821 T6284 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> 1910821 T6271 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> 1910821 T6262 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> 1910850 T6289 oasc.ZkController.register We are http://127.0.0.1:51226/collection1/ and leader is http://127.0.0.1:51226/collection1/
[junit4] 2> 1910850 T6289 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51226
[junit4] 2> 1910850 T6289 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1910850 T6289 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 1910851 T6289 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1910866 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1910866 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1910866 T6289 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1910867 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1910868 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1910868 T6263 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:51226",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51226_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1910960 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1911078 T6284 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> 1911078 T6271 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> 1911078 T6262 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> 1911450 T6240 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 1911450 T6240 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1911453 T6240 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:49628
[junit4] 2> 1911453 T6240 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1911454 T6240 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1911454 T6240 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394482970576
[junit4] 2> 1911454 T6240 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394482970576/'
[junit4] 2> 1911480 T6240 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394482970576/solr.xml
[junit4] 2> 1911531 T6240 oasc.CoreContainer.<init> New CoreContainer 1336735079
[junit4] 2> 1911532 T6240 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394482970576/]
[junit4] 2> 1911533 T6240 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1911534 T6240 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1911534 T6240 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1911534 T6240 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1911534 T6240 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1911535 T6240 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1911535 T6240 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1911535 T6240 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1911536 T6240 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1911543 T6240 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1911543 T6240 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1911544 T6240 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1911544 T6240 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32338/solr
[junit4] 2> 1911544 T6240 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1911545 T6240 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1911576 T6300 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6423660e name:ZooKeeperConnection Watcher:127.0.0.1:32338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1911577 T6240 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1911591 T6240 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1911592 T6302 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c505069 name:ZooKeeperConnection Watcher:127.0.0.1:32338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1911592 T6240 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1911604 T6240 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1912607 T6240 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49628_
[junit4] 2> 1912634 T6240 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49628_
[junit4] 2> 1912637 T6271 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1912638 T6284 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1912638 T6262 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1912638 T6302 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1912659 T6303 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 1912659 T6303 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1912660 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1912660 T6303 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1912661 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1912661 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1912662 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1912662 T6263 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49628",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49628_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1912663 T6263 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1912663 T6263 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1912666 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1912676 T6271 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> 1912676 T6302 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> 1912676 T6284 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> 1912676 T6262 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> 1913662 T6303 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1913662 T6303 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394482970576/collection1
[junit4] 2> 1913662 T6303 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1913663 T6303 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1913663 T6303 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1913664 T6303 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1913664 T6303 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394482970576/collection1/'
[junit4] 2> 1913666 T6303 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394482970576/collection1/lib/classes/' to classloader
[junit4] 2> 1913667 T6303 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394482970576/collection1/lib/README' to classloader
[junit4] 2> 1913668 T6303 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394482970576/collection1/lib/.svn/' to classloader
[junit4] 2> 1913736 T6303 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1913804 T6303 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1913906 T6303 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1913916 T6303 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1914481 T6303 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1914485 T6303 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1914493 T6303 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1914499 T6303 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1914520 T6303 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1914520 T6303 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1394482970576/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/jetty2/
[junit4] 2> 1914520 T6303 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a281902
[junit4] 2> 1914521 T6303 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/jetty2
[junit4] 2> 1914522 T6303 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/jetty2/index/
[junit4] 2> 1914522 T6303 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1914524 T6303 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1394482963253/jetty2/index
[junit4] 2> 1914524 T6303 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=91.5283203125, floorSegmentMB=0.7900390625, forceMergeDeletesPctAllowed=3.936165082632337, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6819702640925855
[junit4] 2> 1914528 T6303 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/index4169841778tmp lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@756db871),segFN=segments_1,generation=1}
[junit4] 2> 1914528 T6303 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1914532 T6303 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1914533 T6303 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1914533 T6303 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1914533 T6303 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1914534 T6303 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1914534 T6303 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1914535 T6303 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1914535 T6303 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1914535 T6303 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1914536 T6303 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1914537 T6303 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1914537 T6303 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1914537 T6303 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1914538 T6303 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1914538 T6303 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1914539 T6303 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1914548 T6303 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1914553 T6303 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1914554 T6303 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1914554 T6303 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=54.072265625, floorSegmentMB=2.0537109375, forceMergeDeletesPctAllowed=18.146429153176, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7297550961684556
[junit4] 2> 1914556 T6303 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/index4169841778tmp lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@756db871),segFN=segments_1,generation=1}
[junit4] 2> 1914557 T6303 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1914557 T6303 oass.SolrIndexSearcher.<init> Opening Searcher@1f60cad2[collection1] main
[junit4] 2> 1914561 T6304 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f60cad2[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1914563 T6303 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1914564 T6240 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0
[junit4] 2> 1914565 T6240 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1914564 T6307 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49628 collection:collection1 shard:shard2
[junit4] 2> 1914566 T6307 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1914585 T6307 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1914587 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1914587 T6307 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1914587 T6307 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1062 name=collection1 org.apache.solr.core.SolrCore@70ab2732 url=http://127.0.0.1:49628/collection1 node=127.0.0.1:49628_ C1062_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:49628, core=collection1, node_name=127.0.0.1:49628_}
[junit4] 2> 1914588 T6307 C1062 P49628 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49628/collection1/
[junit4] 2> 1914588 T6307 C1062 P49628 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1914588 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1914588 T6307 C1062 P49628 oasc.SyncStrategy.syncToMe http://127.0.0.1:49628/collection1/ has no replicas
[junit4] 2> 1914589 T6307 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49628/collection1/ shard2
[junit4] 2> 1914589 T6307 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1914591 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1914592 T6302 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> 1914592 T6262 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> 1914592 T6284 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> 1914592 T6271 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> 1914596 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1914599 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1914702 T6271 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> 1914702 T6262 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> 1914702 T6302 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> 1914702 T6284 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> 1914749 T6307 oasc.ZkController.register We are http://127.0.0.1:49628/collection1/ and leader is http://127.0.0.1:49628/collection1/
[junit4] 2> 1914749 T6307 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49628
[junit4] 2> 1914749 T6307 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1914749 T6307 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 1914749 T6307 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1914751 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1914751 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1914751 T6307 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1914751 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1914752 T6263 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1914753 T6263 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:49628",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49628_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1914762 T6262 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1914865 T6284 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> 1914865 T6271 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> 1914865 T6302 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> 1914865 T6262 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> 1915454 T6240 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 1915454 T6240 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1915457 T6240 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:24175
[junit4] 2> 1915457 T6240 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1915458 T6240 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1915458 T6240 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394482974613
[junit4] 2> 1915458 T6240 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394482974613/'
[junit4] 2> 1915483 T6240 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394482974613/solr.xml
[junit4] 2> 1915535 T6240 oasc.CoreContainer.<init> New CoreContainer 1268222587
[junit4] 2> 1915535 T6240 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1394482974613/
[...truncated too long message...]
r$SolrInstance-1394483825258/master/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394483825258/master/collection1/data/index;done=false>>]
[junit4] 2> 2768591 T6646 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394483825258/master/collection1/data/index
[junit4] 2> 2768603 T6646 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394483825258/master/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394483825258/master/collection1/data;done=false>>]
[junit4] 2> 2768603 T6646 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394483825258/master/collection1/data
[junit4] 2> 2768604 T6646 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 2768657 T6646 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1517663721
[junit4] 2> 2768658 T6646 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@7e814e25
[junit4] 2> 2780064 T7542 oash.SnapPuller.fetchLatestIndex ERROR Master at: http://127.0.0.1:65422/solr is not available. Index fetch failed. Exception: IOException occured when talking to server at: http://127.0.0.1:65422/solr
[junit4] 2> 2780065 T7542 oasc.SolrException.log ERROR SnapPull failed :org.apache.lucene.store.AlreadyClosedException: Already closed
[junit4] 2> at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:340)
[junit4] 2> at org.apache.solr.handler.ReplicationHandler.loadReplicationProperties(ReplicationHandler.java:812)
[junit4] 2> at org.apache.solr.handler.SnapPuller.logReplicationTimeAndConfFiles(SnapPuller.java:566)
[junit4] 2> at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:508)
[junit4] 2> at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:323)
[junit4] 2> at org.apache.solr.handler.ReplicationHandler$1.run(ReplicationHandler.java:224)
[junit4] 2>
[junit4] 2> 2780955 T7566 oash.SnapPuller.fetchLatestIndex ERROR Master at: http://127.0.0.1:57831/solr is not available. Index fetch failed. Exception: IOException occured when talking to server at: http://127.0.0.1:57831/solr
[junit4] 2> 2780956 T6646 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,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}
[junit4] 2> 2780957 T6646 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2780958 T6646 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2780958 T6646 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2780959 T6646 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 2780959 T6646 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2780960 T6646 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394483825591/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394483825591/slave/collection1/data;done=false>>]
[junit4] 2> 2780960 T6646 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394483825591/slave/collection1/data
[junit4] 2> 2780961 T6646 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394483825591/slave/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394483825591/slave/collection1/data/index;done=false>>]
[junit4] 2> 2780962 T6646 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1394483825591/slave/collection1/data/index
[junit4] 2> 2780962 T6646 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 2781026 T6646 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene46: {newname=MockVariableIntBlock(baseBlockSize=84), id=MockVariableIntBlock(baseBlockSize=84), name=MockVariableIntBlock(baseBlockSize=84)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=es_VE, timezone=Africa/Luanda
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=1,free=124316736,total=480313344
[junit4] 2> NOTE: All tests run in this JVM: [ResponseLogComponentTest, EchoParamsTest, SolrCoreTest, JsonLoaderTest, SolrXmlInZkTest, TestExtendedDismaxParser, DeleteReplicaTest, TestLuceneMatchVersion, BJQParserTest, CircularListTest, DirectUpdateHandlerOptimizeTest, AliasIntegrationTest, TestJmxMonitoredMap, ExternalFileFieldSortTest, TestNoOpRegenerator, BasicDistributedZkTest, TestSearchPerf, DistributedTermsComponentTest, TestDefaultSearchFieldResource, TestValueSourceCache, FieldMutatingUpdateProcessorTest, IndexSchemaTest, PolyFieldTest, QueryElevationComponentTest, UpdateParamsTest, TestSolrXml, SpatialFilterTest, SliceStateTest, CustomCollectionTest, TestSchemaVersionResource, LukeRequestHandlerTest, TestOverriddenPrefixQueryForCustomFieldType, DocumentBuilderTest, HdfsDirectoryTest, TestCustomSort, CoreMergeIndexesAdminHandlerTest, LeaderElectionTest, TestConfig, TestSuggestSpellingConverter, TestSolrXmlPersistence, TermsComponentTest, SolrInfoMBeanTest, TestLMDirichletSimilarityFactory, RecoveryZkTest, FileBasedSpellCheckerTest, BasicFunctionalityTest, CoreAdminHandlerTest, AddBlockUpdateTest, UnloadDistributedZkTest, QueryEqualityTest, LegacyHTMLStripCharFilterTest, OverseerCollectionProcessorTest, RemoteQueryErrorTest, SynonymTokenizerTest, TestWriterPerf, TestSolrIndexConfig, TestHighFrequencyDictionaryFactory, ShardRoutingTest, SOLR749Test, TestLRUCache, DocValuesTest, RegexBoostProcessorTest, TestRandomDVFaceting, SuggesterTest, BadComponentTest, TestPseudoReturnFields, SoftAutoCommitTest, CopyFieldTest, DeleteShardTest, HdfsBasicDistributedZkTest, TestFaceting, CacheHeaderTest, CursorMarkTest, TestTrie, TriLevelCompositeIdRoutingTest, TestDocumentBuilder, UUIDFieldTest, DistributedSuggestComponentTest, SpellPossibilityIteratorTest, WordBreakSolrSpellCheckerTest, LoggingHandlerTest, TestCloudManagedSchemaAddField, TestElisionMultitermQuery, DistributedDebugComponentTest, AnalysisErrorHandlingTest, ClusterStateTest, TestFunctionQuery, TestNRTOpen, TestRemoteStreaming, QueryParsingTest, DistributedSpellCheckComponentTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest, OverseerTest, LeaderElectionIntegrationTest, BasicZkTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler]
[junit4] Completed on J0 in 706.60s, 14 tests, 1 failure <<< FAILURES!
[...truncated 549 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:480: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:453: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/common-build.xml:490: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1278: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:911: There were test failures: 369 suites, 1581 tests, 1 suite-level error, 1 failure, 35 ignored (6 assumptions)
Total time: 127 minutes 58 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure