You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/11/24 03:48:20 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.7.0_45) - Build # 8342
- Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/8342/
Java: 32bit/jdk1.7.0_45 -client -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
timeout waiting to see recovered node
Stack Trace:
java.lang.AssertionError: timeout waiting to see recovered node
at __randomizedtesting.SeedInfo.seed([7A9509DF59666FB2:FB7387C72E390F8E]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.SyncSliceTest.waitTillRecovered(SyncSliceTest.java:265)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:188)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 10541 lines...]
[junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4] 2> 922281 T2712 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_/i
[junit4] 2> 922285 T2712 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SyncSliceTest-1385260405158
[junit4] 2> 922285 T2712 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 922286 T2713 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 922386 T2712 oasc.ZkTestServer.run start zk server on port:49380
[junit4] 2> 922387 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 922479 T2719 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1579dcd name:ZooKeeperConnection Watcher:127.0.0.1:49380 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 922480 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 922480 T2712 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 922484 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 922485 T2721 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a98298 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 922485 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 922485 T2712 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 922487 T2712 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 922489 T2712 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 922490 T2712 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 922492 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 922492 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 922495 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 922495 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 922499 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 922499 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 922502 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 922502 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 922504 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 922505 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 922506 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 922507 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 922509 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 922510 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 922513 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 922514 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 922516 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 922516 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 922520 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 922521 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 922523 T2712 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 922523 T2712 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 922592 T2712 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 922596 T2712 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34416
[junit4] 2> 922597 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 922597 T2712 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 922598 T2712 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398
[junit4] 2> 922598 T2712 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/'
[junit4] 2> 922611 T2712 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/solr.xml
[junit4] 2> 922654 T2712 oasc.CoreContainer.<init> New CoreContainer 3613628
[junit4] 2> 922655 T2712 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/]
[junit4] 2> 922656 T2712 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 922656 T2712 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 922656 T2712 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 922656 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 922657 T2712 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 922657 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 922657 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 922658 T2712 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 922658 T2712 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 922659 T2712 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 922659 T2712 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 922660 T2712 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 922660 T2712 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49380/solr
[junit4] 2> 922660 T2712 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 922661 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 922662 T2732 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e83e20 name:ZooKeeperConnection Watcher:127.0.0.1:49380 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 922663 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 922665 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 922666 T2734 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14d2181 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 922666 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 922668 T2712 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 922670 T2712 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 922673 T2712 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 922674 T2712 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34416__%2Fi
[junit4] 2> 922675 T2712 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34416__%2Fi
[junit4] 2> 922677 T2712 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 922681 T2712 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 922683 T2712 oasc.Overseer.start Overseer (id=90784425912565763-127.0.0.1:34416__%2Fi-n_0000000000) starting
[junit4] 2> 922685 T2712 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 922688 T2736 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 922689 T2712 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 922691 T2712 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 922693 T2712 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 922695 T2735 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 922698 T2737 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 922698 T2737 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 922699 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 922699 T2737 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 922700 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 922701 T2735 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:34416/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:34416__%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 922701 T2735 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 922701 T2735 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 922703 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 922704 T2734 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> 923699 T2737 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 923700 T2737 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/collection1
[junit4] 2> 923700 T2737 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 923701 T2737 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 923701 T2737 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 923703 T2737 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/collection1/'
[junit4] 2> 923704 T2737 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/collection1/lib/classes/' to classloader
[junit4] 2> 923704 T2737 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/collection1/lib/README' to classloader
[junit4] 2> 923750 T2737 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 923788 T2737 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 923789 T2737 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 923797 T2737 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 924169 T2737 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 924170 T2737 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 924170 T2737 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 924176 T2737 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 924179 T2737 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 924193 T2737 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 924196 T2737 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 924200 T2737 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 924201 T2737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 924201 T2737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 924201 T2737 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 924203 T2737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 924203 T2737 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 924203 T2737 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 924203 T2737 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-controljetty-1385260405398/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1385260405158/control/data/
[junit4] 2> 924204 T2737 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a4acb0
[junit4] 2> 924204 T2737 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/control/data
[junit4] 2> 924205 T2737 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1385260405158/control/data/index/
[junit4] 2> 924205 T2737 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1385260405158/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 924205 T2737 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/control/data/index
[junit4] 2> 924206 T2737 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@11ad35a
[junit4] 2> 924206 T2737 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@879323 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8e83fd),segFN=segments_1,generation=1}
[junit4] 2> 924206 T2737 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 924209 T2737 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 924209 T2737 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 924210 T2737 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 924210 T2737 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 924210 T2737 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 924211 T2737 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 924211 T2737 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 924212 T2737 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 924212 T2737 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 924212 T2737 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 924213 T2737 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 924213 T2737 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 924213 T2737 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 924214 T2737 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 924214 T2737 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 924215 T2737 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 924218 T2737 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 924222 T2737 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 924222 T2737 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 924223 T2737 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=40.4130859375, floorSegmentMB=1.4091796875, forceMergeDeletesPctAllowed=12.721785723941798, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7052138284692118
[junit4] 2> 924223 T2737 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@879323 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8e83fd),segFN=segments_1,generation=1}
[junit4] 2> 924223 T2737 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 924224 T2737 oass.SolrIndexSearcher.<init> Opening Searcher@19603ef main
[junit4] 2> 924227 T2738 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@19603ef main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 924228 T2737 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 924228 T2737 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34416/_/i collection:control_collection shard:shard1
[junit4] 2> 924229 T2737 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 924234 T2737 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 924235 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924236 T2737 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 924236 T2737 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1053 name=collection1 org.apache.solr.core.SolrCore@1b37baf url=http://127.0.0.1:34416/_/i/collection1 node=127.0.0.1:34416__%2Fi C1053_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:34416/_/i, core=collection1, node_name=127.0.0.1:34416__%2Fi}
[junit4] 2> 924236 T2737 C1053 P34416 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34416/_/i/collection1/
[junit4] 2> 924236 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 924237 T2737 C1053 P34416 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 924237 T2737 C1053 P34416 oasc.SyncStrategy.syncToMe http://127.0.0.1:34416/_/i/collection1/ has no replicas
[junit4] 2> 924237 T2737 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34416/_/i/collection1/ shard1
[junit4] 2> 924237 T2737 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 924239 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924239 T2734 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> 924242 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924243 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 924245 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924348 T2734 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> 924393 T2737 oasc.ZkController.register We are http://127.0.0.1:34416/_/i/collection1/ and leader is http://127.0.0.1:34416/_/i/collection1/
[junit4] 2> 924393 T2737 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34416/_/i
[junit4] 2> 924393 T2737 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 924393 T2737 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 924394 T2737 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 924395 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924395 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924395 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924395 T2737 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 924396 T2712 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 924397 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 924396 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 924397 T2735 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:34416/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:34416__%2Fi",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 924398 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 924399 T2741 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a85b5 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 924400 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 924400 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 924401 T2712 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 924405 T2712 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 924481 T2712 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 924483 T2712 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40182
[junit4] 2> 924485 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 924485 T2712 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 924486 T2712 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279
[junit4] 2> 924486 T2712 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/'
[junit4] 2> 924502 T2734 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> 924502 T2741 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> 924507 T2712 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/solr.xml
[junit4] 2> 924556 T2712 oasc.CoreContainer.<init> New CoreContainer 2576800
[junit4] 2> 924556 T2712 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/]
[junit4] 2> 924557 T2712 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 924557 T2712 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 924558 T2712 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 924558 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 924558 T2712 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 924558 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 924559 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 924559 T2712 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 924559 T2712 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 924560 T2712 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 924561 T2712 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 924561 T2712 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 924561 T2712 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49380/solr
[junit4] 2> 924562 T2712 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 924562 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 924564 T2752 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a4ce66 name:ZooKeeperConnection Watcher:127.0.0.1:49380 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 924565 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 924568 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 924569 T2754 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@46ef9 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 924570 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 924574 T2712 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 925578 T2712 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40182__%2Fi
[junit4] 2> 925579 T2712 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40182__%2Fi
[junit4] 2> 925582 T2734 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 925582 T2754 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 925582 T2741 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 925588 T2755 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 925588 T2755 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 925589 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 925589 T2755 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 925589 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 925590 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 925591 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 925592 T2735 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:40182/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:40182__%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 925592 T2735 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 925593 T2735 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 925596 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 925698 T2734 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> 925698 T2741 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> 925698 T2754 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> 926590 T2755 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 926590 T2755 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/collection1
[junit4] 2> 926590 T2755 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 926591 T2755 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 926591 T2755 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 926592 T2755 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/collection1/'
[junit4] 2> 926593 T2755 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/collection1/lib/classes/' to classloader
[junit4] 2> 926593 T2755 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/collection1/lib/README' to classloader
[junit4] 2> 926629 T2755 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 926666 T2755 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 926667 T2755 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 926675 T2755 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 927061 T2755 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 927062 T2755 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 927062 T2755 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 927068 T2755 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 927071 T2755 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 927080 T2755 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 927083 T2755 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 927086 T2755 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 927087 T2755 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 927087 T2755 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 927087 T2755 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 927088 T2755 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 927088 T2755 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 927089 T2755 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 927089 T2755 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-jetty1-1385260407279/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty1/
[junit4] 2> 927089 T2755 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a4acb0
[junit4] 2> 927090 T2755 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty1
[junit4] 2> 927090 T2755 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty1/index/
[junit4] 2> 927090 T2755 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 927090 T2755 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty1/index
[junit4] 2> 927091 T2755 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@51cc07
[junit4] 2> 927091 T2755 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@151c152 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d9cc80),segFN=segments_1,generation=1}
[junit4] 2> 927091 T2755 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 927094 T2755 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 927094 T2755 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 927095 T2755 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 927095 T2755 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 927095 T2755 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 927095 T2755 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 927096 T2755 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 927096 T2755 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 927096 T2755 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 927097 T2755 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 927097 T2755 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 927098 T2755 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 927098 T2755 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 927098 T2755 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 927099 T2755 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 927099 T2755 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 927101 T2755 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 927104 T2755 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 927104 T2755 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 927105 T2755 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=40.4130859375, floorSegmentMB=1.4091796875, forceMergeDeletesPctAllowed=12.721785723941798, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7052138284692118
[junit4] 2> 927105 T2755 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@151c152 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d9cc80),segFN=segments_1,generation=1}
[junit4] 2> 927106 T2755 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 927106 T2755 oass.SolrIndexSearcher.<init> Opening Searcher@1da3472 main
[junit4] 2> 927110 T2756 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1da3472 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 927112 T2755 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 927112 T2755 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:40182/_/i collection:collection1 shard:shard1
[junit4] 2> 927113 T2755 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 927117 T2755 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 927119 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927119 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927119 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927119 T2755 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 927120 T2755 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1054 name=collection1 org.apache.solr.core.SolrCore@8948c url=http://127.0.0.1:40182/_/i/collection1 node=127.0.0.1:40182__%2Fi C1054_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:40182/_/i, core=collection1, node_name=127.0.0.1:40182__%2Fi}
[junit4] 2> 927120 T2755 C1054 P40182 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40182/_/i/collection1/
[junit4] 2> 927120 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 927120 T2755 C1054 P40182 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 927121 T2755 C1054 P40182 oasc.SyncStrategy.syncToMe http://127.0.0.1:40182/_/i/collection1/ has no replicas
[junit4] 2> 927121 T2755 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40182/_/i/collection1/ shard1
[junit4] 2> 927121 T2755 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 927123 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927125 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927161 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927263 T2734 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> 927263 T2754 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> 927263 T2741 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> 927276 T2755 oasc.ZkController.register We are http://127.0.0.1:40182/_/i/collection1/ and leader is http://127.0.0.1:40182/_/i/collection1/
[junit4] 2> 927276 T2755 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40182/_/i
[junit4] 2> 927276 T2755 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 927277 T2755 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 927277 T2755 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 927278 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927278 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927278 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 927279 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927280 T2712 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 927280 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 927280 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 927282 T2735 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:40182/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:40182__%2Fi",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 927283 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 927357 T2712 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 927358 T2712 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60313
[junit4] 2> 927359 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 927360 T2712 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 927360 T2712 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155
[junit4] 2> 927360 T2712 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/'
[junit4] 2> 927372 T2712 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/solr.xml
[junit4] 2> 927385 T2734 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> 927385 T2741 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> 927385 T2754 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> 927415 T2712 oasc.CoreContainer.<init> New CoreContainer 2474702
[junit4] 2> 927415 T2712 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/]
[junit4] 2> 927416 T2712 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 927417 T2712 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 927417 T2712 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 927417 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 927417 T2712 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 927418 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 927418 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 927418 T2712 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 927419 T2712 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 927420 T2712 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 927420 T2712 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 927420 T2712 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 927421 T2712 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49380/solr
[junit4] 2> 927421 T2712 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 927422 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 927424 T2768 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ef42f4 name:ZooKeeperConnection Watcher:127.0.0.1:49380 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 927424 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 927427 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 927427 T2770 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b9033 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 927428 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 927431 T2712 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 928433 T2712 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60313__%2Fi
[junit4] 2> 928434 T2712 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60313__%2Fi
[junit4] 2> 928437 T2734 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 928437 T2754 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 928437 T2741 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 928437 T2770 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 928442 T2771 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 928443 T2771 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 928539 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 928539 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 928539 T2771 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 928539 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 928541 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 928542 T2735 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:60313/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:60313__%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 928542 T2735 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 928542 T2735 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 928545 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 928648 T2734 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> 928648 T2770 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> 928648 T2754 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> 928648 T2741 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> 929540 T2771 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 929540 T2771 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/collection1
[junit4] 2> 929540 T2771 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 929541 T2771 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 929541 T2771 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 929542 T2771 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/collection1/'
[junit4] 2> 929543 T2771 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/collection1/lib/classes/' to classloader
[junit4] 2> 929544 T2771 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/collection1/lib/README' to classloader
[junit4] 2> 929584 T2771 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 929628 T2771 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 929629 T2771 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 929642 T2771 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 930092 T2771 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 930093 T2771 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 930094 T2771 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 930100 T2771 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 930103 T2771 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 930114 T2771 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 930118 T2771 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 930122 T2771 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 930123 T2771 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 930123 T2771 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 930123 T2771 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 930124 T2771 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 930124 T2771 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 930124 T2771 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 930125 T2771 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1385260410155/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty2/
[junit4] 2> 930125 T2771 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a4acb0
[junit4] 2> 930126 T2771 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty2
[junit4] 2> 930126 T2771 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty2/index/
[junit4] 2> 930126 T2771 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 930127 T2771 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty2/index
[junit4] 2> 930127 T2771 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@a02270
[junit4] 2> 930128 T2771 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9974ea lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1df4a7a),segFN=segments_1,generation=1}
[junit4] 2> 930128 T2771 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 930131 T2771 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 930132 T2771 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 930132 T2771 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 930132 T2771 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 930132 T2771 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 930133 T2771 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 930133 T2771 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 930133 T2771 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 930133 T2771 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 930134 T2771 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 930135 T2771 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 930135 T2771 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 930135 T2771 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 930136 T2771 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 930136 T2771 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 930137 T2771 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 930140 T2771 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 930143 T2771 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 930143 T2771 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 930145 T2771 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=40.4130859375, floorSegmentMB=1.4091796875, forceMergeDeletesPctAllowed=12.721785723941798, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7052138284692118
[junit4] 2> 930145 T2771 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9974ea lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1df4a7a),segFN=segments_1,generation=1}
[junit4] 2> 930145 T2771 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 930146 T2771 oass.SolrIndexSearcher.<init> Opening Searcher@829ef8 main
[junit4] 2> 930152 T2772 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@829ef8 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 930154 T2771 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 930155 T2771 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60313/_/i collection:collection1 shard:shard1
[junit4] 2> 930158 T2771 oasc.ZkController.register We are http://127.0.0.1:60313/_/i/collection1/ and leader is http://127.0.0.1:40182/_/i/collection1/
[junit4] 2> 930159 T2771 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60313/_/i
[junit4] 2> 930159 T2771 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 930159 T2771 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C1055 name=collection1 org.apache.solr.core.SolrCore@98aa61 url=http://127.0.0.1:60313/_/i/collection1 node=127.0.0.1:60313__%2Fi C1055_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:60313/_/i, core=collection1, node_name=127.0.0.1:60313__%2Fi}
[junit4] 2> 930159 T2773 C1055 P60313 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 930160 T2773 C1055 P60313 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 930160 T2771 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 930160 T2773 C1055 P60313 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 930160 T2773 C1055 P60313 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 930161 T2712 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 930161 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 930162 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930162 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930162 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930164 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 930164 T2750 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 930164 T2735 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "base_url":"http://127.0.0.1:60313/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:60313__%2Fi",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 930167 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930168 T2741 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> 930168 T2734 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> 930168 T2770 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> 930168 T2754 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> 930257 T2712 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 930259 T2712 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39878
[junit4] 2> 930259 T2712 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 930260 T2712 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 930260 T2712 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036
[junit4] 2> 930260 T2712 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/'
[junit4] 2> 930276 T2712 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/solr.xml
[junit4] 2> 930349 T2712 oasc.CoreContainer.<init> New CoreContainer 19826714
[junit4] 2> 930350 T2712 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/]
[junit4] 2> 930351 T2712 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 930351 T2712 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 930351 T2712 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 930352 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 930352 T2712 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 930352 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 930353 T2712 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 930353 T2712 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 930354 T2712 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 930356 T2712 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 930356 T2712 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 930357 T2712 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 930357 T2712 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49380/solr
[junit4] 2> 930358 T2712 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 930358 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 930359 T2785 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@130a88f name:ZooKeeperConnection Watcher:127.0.0.1:49380 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 930360 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 930363 T2712 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 930364 T2787 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@862e21 name:ZooKeeperConnection Watcher:127.0.0.1:49380/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 930364 T2712 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 930368 T2712 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 931167 T2750 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 931168 T2750 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node2&state=recovering&nodeName=127.0.0.1:60313__%252Fi&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1004
[junit4] 2> 931370 T2712 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39878__%2Fi
[junit4] 2> 931372 T2712 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39878__%2Fi
[junit4] 2> 931374 T2770 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 931374 T2734 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 931374 T2741 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 931374 T2754 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 931375 T2787 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 931380 T2788 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 931381 T2788 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 931382 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931382 T2788 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 931383 T2735 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 931384 T2735 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:39878/_/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:39878__%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 931384 T2735 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 931384 T2735 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 931386 T2734 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931489 T2770 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> 931489 T2754 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> 931489 T2787 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> 931489 T2741 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> 931489 T2734 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> 932382 T2788 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 932383 T2788 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/collection1
[junit4] 2> 932383 T2788 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 932384 T2788 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 932384 T2788 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 932385 T2788 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/collection1/'
[junit4] 2> 932386 T2788 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/collection1/lib/classes/' to classloader
[junit4] 2> 932386 T2788 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/collection1/lib/README' to classloader
[junit4] 2> 932431 T2788 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 932477 T2788 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 932478 T2788 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 932489 T2788 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 932930 T2788 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 932931 T2788 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 932932 T2788 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 932939 T2788 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 932942 T2788 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 932952 T2788 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 932956 T2788 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 932959 T2788 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 932960 T2788 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 932961 T2788 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 932961 T2788 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 932962 T2788 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 932962 T2788 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 932962 T2788 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 932963 T2788 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.SyncSliceTest-jetty3-1385260413036/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty3/
[junit4] 2> 932963 T2788 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a4acb0
[junit4] 2> 932964 T2788 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty3
[junit4] 2> 932964 T2788 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty3/index/
[junit4] 2> 932964 T2788 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 932965 T2788 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1385260405158/jetty3/index
[junit4] 2> 932965 T2788 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@14e102e
[junit4] 2> 932965 T2788 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@17e5895 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@31b81),segFN=segments_1,generation=1}
[junit4] 2> 932966 T2788 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 932969 T2788 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 932969 T2788 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 932969 T2788 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 932970 T2788 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 932970 T2788 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 932970 T2788 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 932971 T2788 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 932971 T2788 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 932971 T2788 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 932972 T2788 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 932972 T2788 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 932973 T2788 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 932973 T2788 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 932973 T2788 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 932974 T2788 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 932974 T2788 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 932977 T2788 oashl.XMLLoader.init xsltCacheLifetimeSeconds=6
[...truncated too long message...]
"shards":{"shard1":{
[junit4] 1> "range":"80000000-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{"core_node1":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:34416/_/i",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:34416__%2Fi",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "replicationFactor":"1",
[junit4] 1> "autoCreated":"true"}}
[junit4] 1> /solr/aliases.json (0)
[junit4] 1> /solr/live_nodes (4)
[junit4] 1> /solr/live_nodes/127.0.0.1:39878__%2Fi (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:54595__%2Fi (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:60313__%2Fi (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:34416__%2Fi (0)
[junit4] 1> /solr/overseer (3)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1> /solr/overseer/queue (0)
[junit4] 1> /solr/overseer/queue-work (0)
[junit4] 1> /solr/overseer/collection-queue-work (0)
[junit4] 1> /solr/collections (2)
[junit4] 1> /solr/collections/collection1 (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/collection1/shards (0)
[junit4] 1> /solr/collections/collection1/leader_elect (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election (3)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90784425912565772-core_node4-n_0000000003 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90784425912565768-core_node2-n_0000000001 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90784425912565770-core_node3-n_0000000002 (0)
[junit4] 1> /solr/collections/collection1/leaders (1)
[junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:60313__%2Fi",
[junit4] 1> "base_url":"http://127.0.0.1:60313/_/i"}
[junit4] 1> /solr/collections/control_collection (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/control_collection/shards (0)
[junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/90784425912565763-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:34416__%2Fi",
[junit4] 1> "base_url":"http://127.0.0.1:34416/_/i"}
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (4)
[junit4] 1> /solr/overseer_elect/election/90784425912565768-127.0.0.1:60313__%2Fi-n_0000000002 (0)
[junit4] 1> /solr/overseer_elect/election/90784425912565770-127.0.0.1:39878__%2Fi-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/election/90784425912565763-127.0.0.1:34416__%2Fi-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90784425912565772-127.0.0.1:54595__%2Fi-n_0000000004 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90784425912565763-127.0.0.1:34416__%2Fi-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=7A9509DF59666FB2 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_MX -Dtests.timezone=Asia/Kabul -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 131s J1 | SyncSliceTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: timeout waiting to see recovered node
[junit4] > at __randomizedtesting.SeedInfo.seed([7A9509DF59666FB2:FB7387C72E390F8E]:0)
[junit4] > at org.apache.solr.cloud.SyncSliceTest.waitTillRecovered(SyncSliceTest.java:265)
[junit4] > at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:188)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 1053518 T2712 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 131241 T2711 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 1053530 T2787 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1054730 T2805 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene46: {range_facet_l=PostingsFormat(name=MockRandom), text=Lucene41(blocksize=128), _version_=PostingsFormat(name=Memory doPackFST= false), rnd_b=PostingsFormat(name=Asserting), intDefault=PostingsFormat(name=Memory doPackFST= false), timestamp=PostingsFormat(name=MockRandom), id=PostingsFormat(name=Asserting), a_t=PostingsFormat(name=MockRandom), range_facet_sl=PostingsFormat(name=Asserting), range_facet_si=PostingsFormat(name=MockRandom), other_tl1=PostingsFormat(name=Memory doPackFST= false), multiDefault=PostingsFormat(name=MockRandom), a_si=PostingsFormat(name=Memory doPackFST= false)}, docValues:{}, sim=DefaultSimilarity, locale=es_MX, timezone=Asia/Kabul
[junit4] 2> NOTE: Linux 3.8.0-33-generic i386/Oracle Corporation 1.7.0_45 (32-bit)/cpus=8,threads=6,free=125641776,total=302776320
[junit4] 2> NOTE: All tests run in this JVM: [OutputWriterTest, DocumentAnalysisRequestHandlerTest, TestWordDelimiterFilterFactory, SolrIndexConfigTest, MigrateRouteKeyTest, TestBinaryResponseWriter, TestStressLucene, TestRangeQuery, DocValuesMissingTest, NotRequiredUniqueKeyTest, TestBinaryField, TestLazyCores, DirectSolrSpellCheckerTest, HdfsCollectionsAPIDistributedZkTest, TestSolr4Spatial, SignatureUpdateProcessorFactoryTest, TestAtomicUpdateErrorCases, SpellCheckComponentTest, QueryResultKeyTest, AlternateDirectoryTest, DistributedSuggesterComponentTest, TestCSVResponseWriter, CollectionsAPIDistributedZkTest, ConvertedLegacyTest, TestSolrJ, TestSolrXml, ChangedSchemaMergeTest, TestQueryTypes, TestSchemaResource, TestDistributedGrouping, TestQuerySenderListener, TestSolrDeletionPolicy2, HighlighterConfigTest, AliasIntegrationTest, TestJmxIntegration, RequiredFieldsTest, SolrCmdDistributorTest, ChaosMonkeyNothingIsSafeTest, TestRandomMergePolicy, XsltUpdateRequestHandlerTest, InfoHandlerTest, TestSolrXmlPersistence, PreAnalyzedUpdateProcessorTest, DirectSolrConnectionTest, CurrencyFieldXmlFileTest, TestAddFieldRealTimeGet, TestCollapseQParserPlugin, TestStressRecovery, TestFileDictionaryLookup, OpenExchangeRatesOrgProviderTest, TestSchemaVersionResource, StatsComponentTest, TestSolrXmlPersistor, TestFieldTypeCollectionResource, TestCoreDiscovery, BasicDistributedZk2Test, SuggesterWFSTTest, TestCopyFieldCollectionResource, PathHierarchyTokenizerFactoryTest, SortByFunctionTest, BlockCacheTest, HardAutoCommitTest, TestFoldingMultitermQuery, TestOmitPositions, StandardRequestHandlerTest, TestSweetSpotSimilarityFactory, TestStressReorder, TestFuzzyAnalyzedSuggestions, RequestHandlersTest, DistanceFunctionTest, TestRandomFaceting, TestSchemaNameResource, BasicZkTest, SuggesterTSTTest, DocValuesMultiTest, SolrXmlInZkTest, PreAnalyzedFieldTest, TestPartialUpdateDeduplication, TestReloadAndDeleteDocs, SimplePostToolTest, TestUtils, ChaosMonkeySafeLeaderTest, TestSolrQueryParserDefaultOperatorResource, IndexSchemaRuntimeFieldTest, SpellingQueryConverterTest, SyncSliceTest]
[junit4] Completed on J1 in 132.52s, 1 test, 1 failure <<< FAILURES!
[...truncated 526 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:426: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:406: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:492: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1276: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:912: There were test failures: 345 suites, 1505 tests, 1 failure, 34 ignored (6 assumptions)
Total time: 55 minutes 18 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_45 -client -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure