Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4786/
1 tests failed.
FAILED: org.apache.solr.cloud.MultiThreadedOCPTest.testDistribSearch
Error Message:
We have a failed SPLITSHARD task
Stack Trace:
java.lang.AssertionError: We have a failed SPLITSHARD task
at
__randomizedtesting.SeedInfo.seed([B2526CA8AF3CA5D1:33B4E2B0D863C5ED]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at
org.apache.solr.cloud.MultiThreadedOCPTest.testTaskExclusivity(MultiThreadedOCPTest.java:125)
at
org.apache.solr.cloud.MultiThreadedOCPTest.doTest(MultiThreadedOCPTest.java:71)
at
org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11279 lines...]
[junit4] Suite: org.apache.solr.cloud.MultiThreadedOCPTest
[junit4] 2> Creating dataDir:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/init-core-data-001
[junit4] 2> 936325 T7678 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl
(false) and clientAuth (false)
[junit4] 2> 936326 T7678 oas.BaseDistributedSearchTestCase.initHostContext
Setting hostContext system property: /
[junit4] 2> 936330 T7678 oas.SolrTestCaseJ4.setUp ###Starting
testDistribSearch
[junit4] 2> 936331 T7678 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 936331 T7679 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 936431 T7678 oasc.ZkTestServer.run start zk server on
port:10388
[junit4] 2> 936432 T7678 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 936434 T7685 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@605145a name:ZooKeeperConnection
Watcher:127.0.0.1:10388 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 936435 T7678 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 936435 T7678 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 936438 T7678 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 936439 T7687 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@397297e name:ZooKeeperConnection
Watcher:127.0.0.1:10388/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 936439 T7678 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 936439 T7678 oascc.SolrZkClient.makePath makePath:
/collections/collection1
[junit4] 2> 936441 T7678 oascc.SolrZkClient.makePath makePath:
/collections/collection1/shards
[junit4] 2> 936442 T7678 oascc.SolrZkClient.makePath makePath:
/collections/control_collection
[junit4] 2> 936443 T7678 oascc.SolrZkClient.makePath makePath:
/collections/control_collection/shards
[junit4] 2> 936445 T7678 oasc.AbstractZkTestCase.putConfig put
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml
to /configs/conf1/solrconfig.xml
[junit4] 2> 936446 T7678 oascc.SolrZkClient.makePath makePath:
/configs/conf1/solrconfig.xml
[junit4] 2> 936448 T7678 oasc.AbstractZkTestCase.putConfig put
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/schema.xml
to /configs/conf1/schema.xml
[junit4] 2> 936448 T7678 oascc.SolrZkClient.makePath makePath:
/configs/conf1/schema.xml
[junit4] 2> 936550 T7678 oasc.AbstractZkTestCase.putConfig put
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml
to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 936551 T7678 oascc.SolrZkClient.makePath makePath:
/configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 936552 T7678 oasc.AbstractZkTestCase.putConfig put
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/stopwords.txt
to /configs/conf1/stopwords.txt
[junit4] 2> 936553 T7678 oascc.SolrZkClient.makePath makePath:
/configs/conf1/stopwords.txt
[junit4] 2> 936555 T7678 oasc.AbstractZkTestCase.putConfig put
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/protwords.txt
to /configs/conf1/protwords.txt
[junit4] 2> 936555 T7678 oascc.SolrZkClient.makePath makePath:
/configs/conf1/protwords.txt
[junit4] 2> 936557 T7678 oasc.AbstractZkTestCase.putConfig put
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/currency.xml
to /configs/conf1/currency.xml
[junit4] 2> 936558 T7678 oascc.SolrZkClient.makePath makePath:
/configs/conf1/currency.xml
[junit4] 2> 936559 T7678 oasc.AbstractZkTestCase.putConfig put
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml
to /configs/conf1/enumsConfig.xml
[junit4] 2> 936560 T7678 oascc.SolrZkClient.makePath makePath:
/configs/conf1/enumsConfig.xml
[junit4] 2> 936562 T7678 oasc.AbstractZkTestCase.putConfig put
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json
to /configs/conf1/open-exchange-rates.json
[junit4] 2> 936562 T7678 oascc.SolrZkClient.makePath makePath:
/configs/conf1/open-exchange-rates.json
[junit4] 2> 936564 T7678 oasc.AbstractZkTestCase.putConfig put
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt
to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 936565 T7678 oascc.SolrZkClient.makePath makePath:
/configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 936566 T7678 oasc.AbstractZkTestCase.putConfig put
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt
to /configs/conf1/old_synonyms.txt
[junit4] 2> 936567 T7678 oascc.SolrZkClient.makePath makePath:
/configs/conf1/old_synonyms.txt
[junit4] 2> 936569 T7678 oasc.AbstractZkTestCase.putConfig put
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/conf/synonyms.txt
to /configs/conf1/synonyms.txt
[junit4] 2> 936569 T7678 oascc.SolrZkClient.makePath makePath:
/configs/conf1/synonyms.txt
[junit4] 2> 937860 T7678 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 937864 T7678 oejs.AbstractConnector.doStart Started
[email protected]:10394
[junit4] 2> 937864 T7678 oass.SolrDispatchFilter.init
SolrDispatchFilter.init()
[junit4] 2> 937864 T7678 oasc.SolrResourceLoader.locateSolrHome JNDI not
configured for solr (NoInitialContextEx)
[junit4] 2> 937865 T7678 oasc.SolrResourceLoader.locateSolrHome using
system property solr.solr.home:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-002
[junit4] 2> 937865 T7678 oasc.SolrResourceLoader.<init> new
SolrResourceLoader for directory:
'/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-002/'
[junit4] 2> 937897 T7678 oasc.ConfigSolr.fromFile Loading container
configuration from
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-002/solr.xml
[junit4] 2> 937952 T7678 oasc.CoreContainer.<init> New CoreContainer
687547294
[junit4] 2> 937952 T7678 oasc.CoreContainer.load Loading cores into
CoreContainer
[instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-002/]
[junit4] 2> 937953 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting socketTimeout to: 90000
[junit4] 2> 937953 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting urlScheme to:
[junit4] 2> 937954 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting connTimeout to: 15000
[junit4] 2> 937954 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting maxConnectionsPerHost to: 20
[junit4] 2> 937954 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting corePoolSize to: 0
[junit4] 2> 937954 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting maximumPoolSize to: 2147483647
[junit4] 2> 937955 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting maxThreadIdleTime to: 5
[junit4] 2> 937955 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting sizeOfQueue to: -1
[junit4] 2> 937955 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting fairnessPolicy to: false
[junit4] 2> 937956 T7678 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 937956 T7678 oasl.LogWatcher.createWatcher SLF4J impl is
org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 937956 T7678 oasl.LogWatcher.newRegisteredLogWatcher
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 937956 T7678 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 937957 T7678 oasc.ZkContainer.initZooKeeper Zookeeper
client=127.0.0.1:10388/solr
[junit4] 2> 937957 T7678 oasc.ZkController.checkChrootPath zkHost includes
chroot
[junit4] 2> 937958 T7678 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 937959 T7698 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7fdf6f16
name:ZooKeeperConnection Watcher:127.0.0.1:10388 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 937960 T7678 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 937962 T7678 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 937963 T7700 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5404ee5 name:ZooKeeperConnection
Watcher:127.0.0.1:10388/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 937963 T7678 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 937965 T7678 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 937967 T7678 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 937969 T7678 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 937971 T7678 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 937973 T7678 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 937976 T7678 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 937977 T7678 oasc.ZkController.createEphemeralLiveNode
Register node as live in ZooKeeper:/live_nodes/127.0.0.1:10394_
[junit4] 2> 937977 T7678 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1:10394_
[junit4] 2> 937979 T7678 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 937981 T7678 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 937983 T7678 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:10394_
[junit4] 2> 937984 T7678 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 937985 T7678 oasc.Overseer.start Overseer
(id=92199711310217219-127.0.0.1:10394_-n_0000000000) starting
[junit4] 2> 937987 T7678 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 937993 T7702 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 937994 T7678 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 937995 T7678 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 937997 T7678
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 937998 T7701 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 938003 T7703 oasc.ZkController.publish publishing
core=collection1 state=down collection=control_collection
[junit4] 2> 938004 T7703 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 938005 T7703 oasc.ZkController.waitForCoreNodeName look for
our core node name
[junit4] 2> 938005 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 938006 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 938006 T7701 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:10394";,
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:10394_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 938006 T7701
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
control_collection with shards [shard1]
[junit4] 2> 938007 T7701 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 938008 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 938009 T7704 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> 939005 T7703 oasc.ZkController.waitForShardId waiting to find
shard id in clusterstate for collection1
[junit4] 2> 939006 T7703 oasc.ZkController.createCollectionZkNode Check
for collection zkNode:control_collection
[junit4] 2> 939007 T7703 oasc.ZkController.createCollectionZkNode
Collection zkNode exists
[junit4] 2> 939007 T7703 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/control_collection
[junit4] 2> 939007 T7703 oascc.ZkStateReader.readConfigName
path=/collections/control_collection configName=conf1 specified config exists
in ZooKeeper
[junit4] 2> 939008 T7703 oasc.SolrResourceLoader.<init> new
SolrResourceLoader for directory:
'/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-002/collection1/'
[junit4] 2> 939009 T7703 oasc.SolrResourceLoader.replaceClassLoader Adding
'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-002/collection1/lib/classes/'
to classloader
[junit4] 2> 939010 T7703 oasc.SolrResourceLoader.replaceClassLoader Adding
'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-002/collection1/lib/.svn/'
to classloader
[junit4] 2> 939011 T7703 oasc.SolrResourceLoader.replaceClassLoader Adding
'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-002/collection1/lib/README'
to classloader
[junit4] 2> 939078 T7703 oasc.SolrConfig.<init> Using Lucene MatchVersion:
LUCENE_5_0
[junit4] 2> 939126 T7703 oasc.SolrConfig.<init> Loaded SolrConfig:
solrconfig.xml
[junit4] 2> 939228 T7703 oass.IndexSchema.readSchema Reading Solr Schema
from schema.xml
[junit4] 2> 939239 T7703 oass.IndexSchema.readSchema [collection1] Schema
name=test
[junit4] 2> 939620 T7703 oass.OpenExchangeRatesOrgProvider.init
Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 939634 T7703 oass.IndexSchema.readSchema default search field
in schema is text
[junit4] 2> 939637 T7703 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 939649 T7703 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 939653 T7703 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 939657 T7703 oass.OpenExchangeRatesOrgProvider.reload
Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 939658 T7703
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 939659 T7703
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 939660 T7703 oass.OpenExchangeRatesOrgProvider.reload
Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 939660 T7703
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 939661 T7703
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 939661 T7703 oasc.CoreContainer.create Creating SolrCore
'collection1' using configuration from collection control_collection
[junit4] 2> 939661 T7703 oasc.SolrCore.initDirectoryFactory
org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 939661 T7703 oasc.SolrCore.<init> [collection1] Opening new
SolrCore at
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-002/collection1/,
dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-001/control/data/
[junit4] 2> 939662 T7703 oasc.JmxMonitoredMap.<init> JMX monitoring is
enabled. Adding Solr mbeans to JMX Server:
com.sun.jmx.mbeanserver.JmxMBeanServer@185af219
[junit4] 2> 939663 T7703 oasc.CachingDirectoryFactory.get return new
directory for
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-001/control/data
[junit4] 2> 939663 T7703 oasc.SolrCore.getNewIndexDir New index directory
detected: old=null
new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-001/control/data/index/
[junit4] 2> 939663 T7703 oasc.SolrCore.initIndex WARN [collection1] Solr
index directory
'/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-001/control/data/index'
doesn't exist. Creating new index...
[junit4] 2> 939663 T7703 oasc.CachingDirectoryFactory.get return new
directory for
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-001/control/data/index
[junit4] 2> 939664 T7703 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.AlcoholicMergePolicy:
[AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1809299489,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 939665 T7703 oasc.SolrDeletionPolicy.onCommit
SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2>
commit{dir=MockDirectoryWrapper(RAMDirectory@7b34a30e
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7945e4c9),segFN=segments_1,generation=1}
[junit4] 2> 939665 T7703 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 939670 T7703 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "nodistrib"
[junit4] 2> 939670 T7703 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "dedupe"
[junit4] 2> 939671 T7703 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 939671 T7703 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "stored_sig"
[junit4] 2> 939671 T7703 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 939671 T7703 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 939672 T7703 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 939672 T7703 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 939673 T7703 oasc.SolrCore.loadUpdateProcessorChains no
updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 939673 T7703 oasc.RequestHandlers.initHandlersFromConfig
created standard: solr.StandardRequestHandler
[junit4] 2> 939674 T7703 oasc.RequestHandlers.initHandlersFromConfig
created /get: solr.RealTimeGetHandler
[junit4] 2> 939674 T7703 oasc.RequestHandlers.initHandlersFromConfig
adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 939674 T7703 oasc.RequestHandlers.initHandlersFromConfig
created /replication: solr.ReplicationHandler
[junit4] 2> 939675 T7703 oasc.RequestHandlers.initHandlersFromConfig
created /update: solr.UpdateRequestHandler
[junit4] 2> 939675 T7703 oasc.RequestHandlers.initHandlersFromConfig
created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 939676 T7703 oasc.RequestHandlers.initHandlersFromConfig
created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 939676 T7703 oasc.RequestHandlers.initHandlersFromConfig
created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 939695 T7703 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 939701 T7703 oasu.CommitTracker.<init> Hard AutoCommit:
disabled
[junit4] 2> 939701 T7703 oasu.CommitTracker.<init> Soft AutoCommit:
disabled
[junit4] 2> 939702 T7703 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.LogByteSizeMergePolicy:
[LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=31,
maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807,
calibrateSizeByDeletes=false, maxMergeDocs=2147483647,
maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 939702 T7703 oasc.SolrDeletionPolicy.onInit
SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2>
commit{dir=MockDirectoryWrapper(RAMDirectory@7b34a30e
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7945e4c9),segFN=segments_1,generation=1}
[junit4] 2> 939703 T7703 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 939703 T7703 oass.SolrIndexSearcher.<init> Opening
Searcher@612f6d9d[collection1] main
[junit4] 2> 939703 T7703 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/control_collection
[junit4] 2> 939704 T7703 oascc.ZkStateReader.readConfigName
path=/collections/control_collection configName=conf1 specified config exists
in ZooKeeper
[junit4] 2> 939704 T7703 oasr.ManagedResourceStorage.newStorageIO Setting
up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 939705 T7703
oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured
ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 939705 T7703 oasr.RestManager.init Initializing RestManager
with initArgs: {}
[junit4] 2> 939705 T7703 oasr.ManagedResourceStorage.load Reading
_rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 939706 T7703
oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found
for znode /configs/conf1/_rest_managed.json
[junit4] 2> 939706 T7703 oasr.ManagedResourceStorage.load Loaded null at
path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 939707 T7703 oascc.SolrZkClient.makePath makePath:
/configs/conf1/_rest_managed.json
[junit4] 2> 939709 T7703
oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new
znode /configs/conf1/_rest_managed.json
[junit4] 2> 939709 T7703 oasr.ManagedResourceStorage$JsonStorage.store
Saved JSON object to path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 939709 T7703 oasr.RestManager.init Initializing 0 registered
ManagedResources
[junit4] 2> 939712 T7705 oasc.SolrCore.registerSearcher [collection1]
Registered new searcher Searcher@612f6d9d[collection1]
main{UninvertingDirectoryReader()}
[junit4] 2> 939714 T7703 oasc.CoreContainer.registerCore registering core:
collection1
[junit4] 2> 939714 T7708 oasc.ZkController.register Register replica -
core:collection1 address:http://127.0.0.1:10394 collection:control_collection
shard:shard1
[junit4] 2> 939715 T7678 oass.SolrDispatchFilter.init
user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4] 2> 939715 T7678 oass.SolrDispatchFilter.init
SolrDispatchFilter.init() done
[junit4] 2> 939715 T7708 oascc.SolrZkClient.makePath makePath:
/collections/control_collection/leader_elect/shard1/election
[junit4] 2> 939717 T7678 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 939718 T7710 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@206fed2d
name:ZooKeeperConnection Watcher:127.0.0.1:10388/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 939718 T7678 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 939719 T7678
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 939721 T7708 oasc.ShardLeaderElectionContext.runLeaderProcess
Running the leader process for shard shard1
[junit4] 2> 939721 T7678 oasc.ChaosMonkey.monkeyLog monkey: init - expire
sessions:false cause connection loss:false
[junit4] 2> 939722 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 939722 T7708
oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found
to continue.
[junit4] 2> 939723 T7708 oasc.ShardLeaderElectionContext.runLeaderProcess
I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C425 name=collection1
org.apache.solr.core.SolrCore@311b710c url=http://127.0.0.1:10394/collection1
node=127.0.0.1:10394_ C425_STATE=coll:control_collection core:collection1
props:{state=down, base_url=http://127.0.0.1:10394, core=collection1,
node_name=127.0.0.1:10394_}
[junit4] 2> 939723 T7708 C425 P10394 oasc.SyncStrategy.sync Sync replicas
to http://127.0.0.1:10394/collection1/
[junit4] 2> 939723 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 939723 T7708 C425 P10394 oasc.SyncStrategy.syncReplicas Sync
Success - now sync replicas to me
[junit4] 2> 939724 T7708 C425 P10394 oasc.SyncStrategy.syncToMe
http://127.0.0.1:10394/collection1/ has no replicas
[junit4] 2> 939724 T7708 oasc.ShardLeaderElectionContext.runLeaderProcess
I am the new leader: http://127.0.0.1:10394/collection1/ shard1
[junit4] 2> 939724 T7708 oascc.SolrZkClient.makePath makePath:
/collections/control_collection/leaders/shard1
[junit4] 2> 939725 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 939726 T7704 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> 939726 T7711 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> 939729 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 939731 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 939832 T7711 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> 939832 T7704 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> 939881 T7708 oasc.ZkController.register We are
http://127.0.0.1:10394/collection1/ and leader is
http://127.0.0.1:10394/collection1/
[junit4] 2> 939882 T7708 oasc.ZkController.register No LogReplay needed
for core=collection1 baseURL=http://127.0.0.1:10394
[junit4] 2> 939882 T7708 oasc.ZkController.checkRecovery I am the leader,
no recovery necessary
[junit4] 2> 939882 T7708 oasc.ZkController.publish publishing
core=collection1 state=active collection=control_collection
[junit4] 2> 939882 T7708 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 939884 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 939884 T7712 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 939884 T7713 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 939884 T7708 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 939886 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 939886 T7701 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:10394";,
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:10394_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 939888 T7713 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 939990 T7713 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> 939990 T7711 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> 941249 T7678 oasc.AbstractFullDistribZkTestBase.createJettys
create jetty 1
[junit4] 2> 941250 T7678 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 941253 T7678 oejs.AbstractConnector.doStart Started
[email protected]:10401
[junit4] 2> 941253 T7678 oass.SolrDispatchFilter.init
SolrDispatchFilter.init()
[junit4] 2> 941253 T7678 oasc.SolrResourceLoader.locateSolrHome JNDI not
configured for solr (NoInitialContextEx)
[junit4] 2> 941254 T7678 oasc.SolrResourceLoader.locateSolrHome using
system property solr.solr.home:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003
[junit4] 2> 941254 T7678 oasc.SolrResourceLoader.<init> new
SolrResourceLoader for directory:
'/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/'
[junit4] 2> 941299 T7678 oasc.ConfigSolr.fromFile Loading container
configuration from
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/solr.xml
[junit4] 2> 941372 T7678 oasc.CoreContainer.<init> New CoreContainer
385269860
[junit4] 2> 941373 T7678 oasc.CoreContainer.load Loading cores into
CoreContainer
[instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/]
[junit4] 2> 941374 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting socketTimeout to: 90000
[junit4] 2> 941374 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting urlScheme to:
[junit4] 2> 941374 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting connTimeout to: 15000
[junit4] 2> 941375 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting maxConnectionsPerHost to: 20
[junit4] 2> 941375 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting corePoolSize to: 0
[junit4] 2> 941375 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting maximumPoolSize to: 2147483647
[junit4] 2> 941375 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting maxThreadIdleTime to: 5
[junit4] 2> 941376 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting sizeOfQueue to: -1
[junit4] 2> 941376 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting fairnessPolicy to: false
[junit4] 2> 941376 T7678 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 941377 T7678 oasl.LogWatcher.createWatcher SLF4J impl is
org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 941377 T7678 oasl.LogWatcher.newRegisteredLogWatcher
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 941377 T7678 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 941377 T7678 oasc.ZkContainer.initZooKeeper Zookeeper
client=127.0.0.1:10388/solr
[junit4] 2> 941378 T7678 oasc.ZkController.checkChrootPath zkHost includes
chroot
[junit4] 2> 941378 T7678 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 941380 T7724 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@21d0f103
name:ZooKeeperConnection Watcher:127.0.0.1:10388 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 941380 T7678 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 941382 T7678 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 941383 T7726 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7962d644
name:ZooKeeperConnection Watcher:127.0.0.1:10388/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 941383 T7678 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 941387 T7678
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 942390 T7678 oasc.ZkController.createEphemeralLiveNode
Register node as live in ZooKeeper:/live_nodes/127.0.0.1:10401_
[junit4] 2> 942391 T7678 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1:10401_
[junit4] 2> 942401 T7728 oasc.ZkController.publish publishing
core=collection1 state=down collection=collection1
[junit4] 2> 942401 T7728 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 942402 T7713 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 942402 T7712 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 942402 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 942402 T7728 oasc.ZkController.waitForCoreNodeName look for
our core node name
[junit4] 2> 942404 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 942405 T7701 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:10401";,
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:10401_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 942405 T7701
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1, shard2]
[junit4] 2> 942405 T7701 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 942407 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 942408 T7704 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> 942408 T7711 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> 942408 T7727 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> 943403 T7728 oasc.ZkController.waitForShardId waiting to find
shard id in clusterstate for collection1
[junit4] 2> 943404 T7728 oasc.ZkController.createCollectionZkNode Check
for collection zkNode:collection1
[junit4] 2> 943405 T7728 oasc.ZkController.createCollectionZkNode
Collection zkNode exists
[junit4] 2> 943405 T7728 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/collection1
[junit4] 2> 943406 T7728 oascc.ZkStateReader.readConfigName
path=/collections/collection1 configName=conf1 specified config exists in
ZooKeeper
[junit4] 2> 943406 T7728 oasc.SolrResourceLoader.<init> new
SolrResourceLoader for directory:
'/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/collection1/'
[junit4] 2> 943407 T7728 oasc.SolrResourceLoader.replaceClassLoader Adding
'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/collection1/lib/README'
to classloader
[junit4] 2> 943408 T7728 oasc.SolrResourceLoader.replaceClassLoader Adding
'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/collection1/lib/classes/'
to classloader
[junit4] 2> 943409 T7728 oasc.SolrResourceLoader.replaceClassLoader Adding
'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/collection1/lib/.svn/'
to classloader
[junit4] 2> 943500 T7728 oasc.SolrConfig.<init> Using Lucene MatchVersion:
LUCENE_5_0
[junit4] 2> 943549 T7728 oasc.SolrConfig.<init> Loaded SolrConfig:
solrconfig.xml
[junit4] 2> 943651 T7728 oass.IndexSchema.readSchema Reading Solr Schema
from schema.xml
[junit4] 2> 943662 T7728 oass.IndexSchema.readSchema [collection1] Schema
name=test
[junit4] 2> 944043 T7728 oass.OpenExchangeRatesOrgProvider.init
Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 944057 T7728 oass.IndexSchema.readSchema default search field
in schema is text
[junit4] 2> 944060 T7728 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 944071 T7728 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 944076 T7728 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 944081 T7728 oass.OpenExchangeRatesOrgProvider.reload
Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 944081 T7728
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 944083 T7728
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 944083 T7728 oass.OpenExchangeRatesOrgProvider.reload
Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 944084 T7728
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 944084 T7728
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 944084 T7728 oasc.CoreContainer.create Creating SolrCore
'collection1' using configuration from collection collection1
[junit4] 2> 944085 T7728 oasc.SolrCore.initDirectoryFactory
org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 944085 T7728 oasc.SolrCore.<init> [collection1] Opening new
SolrCore at
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/collection1/,
dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/collection1/data/
[junit4] 2> 944085 T7728 oasc.JmxMonitoredMap.<init> JMX monitoring is
enabled. Adding Solr mbeans to JMX Server:
com.sun.jmx.mbeanserver.JmxMBeanServer@185af219
[junit4] 2> 944086 T7728 oasc.CachingDirectoryFactory.get return new
directory for
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/collection1/data
[junit4] 2> 944086 T7728 oasc.SolrCore.getNewIndexDir New index directory
detected: old=null
new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/collection1/data/index/
[junit4] 2> 944087 T7728 oasc.SolrCore.initIndex WARN [collection1] Solr
index directory
'/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/collection1/data/index'
doesn't exist. Creating new index...
[junit4] 2> 944087 T7728 oasc.CachingDirectoryFactory.get return new
directory for
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-003/collection1/data/index
[junit4] 2> 944088 T7728 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.AlcoholicMergePolicy:
[AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1809299489,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 944089 T7728 oasc.SolrDeletionPolicy.onCommit
SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2>
commit{dir=MockDirectoryWrapper(RAMDirectory@78399990
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@569a1815),segFN=segments_1,generation=1}
[junit4] 2> 944089 T7728 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 944095 T7728 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "nodistrib"
[junit4] 2> 944095 T7728 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "dedupe"
[junit4] 2> 944096 T7728 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 944096 T7728 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "stored_sig"
[junit4] 2> 944096 T7728 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 944096 T7728 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 944097 T7728 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 944097 T7728 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 944097 T7728 oasc.SolrCore.loadUpdateProcessorChains no
updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 944098 T7728 oasc.RequestHandlers.initHandlersFromConfig
created standard: solr.StandardRequestHandler
[junit4] 2> 944099 T7728 oasc.RequestHandlers.initHandlersFromConfig
created /get: solr.RealTimeGetHandler
[junit4] 2> 944099 T7728 oasc.RequestHandlers.initHandlersFromConfig
adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 944099 T7728 oasc.RequestHandlers.initHandlersFromConfig
created /replication: solr.ReplicationHandler
[junit4] 2> 944100 T7728 oasc.RequestHandlers.initHandlersFromConfig
created /update: solr.UpdateRequestHandler
[junit4] 2> 944100 T7728 oasc.RequestHandlers.initHandlersFromConfig
created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 944101 T7728 oasc.RequestHandlers.initHandlersFromConfig
created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 944102 T7728 oasc.RequestHandlers.initHandlersFromConfig
created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 944121 T7728 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 944127 T7728 oasu.CommitTracker.<init> Hard AutoCommit:
disabled
[junit4] 2> 944127 T7728 oasu.CommitTracker.<init> Soft AutoCommit:
disabled
[junit4] 2> 944128 T7728 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.LogByteSizeMergePolicy:
[LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=31,
maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807,
calibrateSizeByDeletes=false, maxMergeDocs=2147483647,
maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 944129 T7728 oasc.SolrDeletionPolicy.onInit
SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2>
commit{dir=MockDirectoryWrapper(RAMDirectory@78399990
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@569a1815),segFN=segments_1,generation=1}
[junit4] 2> 944129 T7728 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 944129 T7728 oass.SolrIndexSearcher.<init> Opening
Searcher@3b99a7e5[collection1] main
[junit4] 2> 944130 T7728 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/collection1
[junit4] 2> 944131 T7728 oascc.ZkStateReader.readConfigName
path=/collections/collection1 configName=conf1 specified config exists in
ZooKeeper
[junit4] 2> 944131 T7728 oasr.ManagedResourceStorage.newStorageIO Setting
up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 944131 T7728
oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured
ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 944132 T7728 oasr.RestManager.init Initializing RestManager
with initArgs: {}
[junit4] 2> 944132 T7728 oasr.ManagedResourceStorage.load Reading
_rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 944133 T7728
oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes
from znode /configs/conf1/_rest_managed.json
[junit4] 2> 944133 T7728 oasr.ManagedResourceStorage.load Loaded
LinkedHashMap at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 944133 T7728 oasr.ManagedResource.reloadFromStorage Loaded
initArgs {} for /rest/managed
[junit4] 2> 944133 T7728 oasr.RestManager.init Initializing 0 registered
ManagedResources
[junit4] 2> 944138 T7729 oasc.SolrCore.registerSearcher [collection1]
Registered new searcher Searcher@3b99a7e5[collection1]
main{UninvertingDirectoryReader()}
[junit4] 2> 944141 T7728 oasc.CoreContainer.registerCore registering core:
collection1
[junit4] 2> 944142 T7732 oasc.ZkController.register Register replica -
core:collection1 address:http://127.0.0.1:10401 collection:collection1
shard:shard1
[junit4] 2> 944142 T7678 oass.SolrDispatchFilter.init
user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4] 2> 944143 T7678 oass.SolrDispatchFilter.init
SolrDispatchFilter.init() done
[junit4] 2> 944143 T7732 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 944147 T7732 oasc.ShardLeaderElectionContext.runLeaderProcess
Running the leader process for shard shard1
[junit4] 2> 944149 T7732
oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found
to continue.
[junit4] 2> 944150 T7732 oasc.ShardLeaderElectionContext.runLeaderProcess
I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C426 name=collection1
org.apache.solr.core.SolrCore@38e417c7 url=http://127.0.0.1:10401/collection1
node=127.0.0.1:10401_ C426_STATE=coll:collection1 core:collection1
props:{state=down, base_url=http://127.0.0.1:10401, core=collection1,
node_name=127.0.0.1:10401_}
[junit4] 2> 944150 T7732 C426 P10401 oasc.SyncStrategy.sync Sync replicas
to http://127.0.0.1:10401/collection1/
[junit4] 2> 944151 T7732 C426 P10401 oasc.SyncStrategy.syncReplicas Sync
Success - now sync replicas to me
[junit4] 2> 944151 T7732 C426 P10401 oasc.SyncStrategy.syncToMe
http://127.0.0.1:10401/collection1/ has no replicas
[junit4] 2> 944151 T7732 oasc.ShardLeaderElectionContext.runLeaderProcess
I am the new leader: http://127.0.0.1:10401/collection1/ shard1
[junit4] 2> 944151 T7732 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 944162 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 944163 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 944166 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 944166 T7704 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> 944166 T7727 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> 944166 T7711 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> 944169 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 944171 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 944273 T7704 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> 944273 T7727 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> 944273 T7711 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> 944310 T7732 oasc.ZkController.register We are
http://127.0.0.1:10401/collection1/ and leader is
http://127.0.0.1:10401/collection1/
[junit4] 2> 944311 T7732 oasc.ZkController.register No LogReplay needed
for core=collection1 baseURL=http://127.0.0.1:10401
[junit4] 2> 944311 T7732 oasc.ZkController.checkRecovery I am the leader,
no recovery necessary
[junit4] 2> 944311 T7732 oasc.ZkController.publish publishing
core=collection1 state=active collection=collection1
[junit4] 2> 944311 T7732 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 944313 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 944313 T7732 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 944313 T7712 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 944313 T7713 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 944315 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 944315 T7701 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:10401";,
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:10401_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 944317 T7713 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 944420 T7713 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> 944420 T7727 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> 944420 T7711 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> 945588 T7678 oasc.AbstractFullDistribZkTestBase.createJettys
create jetty 2
[junit4] 2> 945589 T7678 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 945592 T7678 oejs.AbstractConnector.doStart Started
[email protected]:10410
[junit4] 2> 945593 T7678 oass.SolrDispatchFilter.init
SolrDispatchFilter.init()
[junit4] 2> 945593 T7678 oasc.SolrResourceLoader.locateSolrHome JNDI not
configured for solr (NoInitialContextEx)
[junit4] 2> 945593 T7678 oasc.SolrResourceLoader.locateSolrHome using
system property solr.solr.home:
../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004
[junit4] 2> 945593 T7678 oasc.SolrResourceLoader.<init> new
SolrResourceLoader for directory:
'../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/'
[junit4] 2> 945629 T7678 oasc.ConfigSolr.fromFile Loading container
configuration from
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/solr.xml
[junit4] 2> 945688 T7678 oasc.CoreContainer.<init> New CoreContainer
2011693227
[junit4] 2> 945689 T7678 oasc.CoreContainer.load Loading cores into
CoreContainer
[instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/]
[junit4] 2> 945690 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting socketTimeout to: 90000
[junit4] 2> 945690 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting urlScheme to:
[junit4] 2> 945690 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting connTimeout to: 15000
[junit4] 2> 945690 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting maxConnectionsPerHost to: 20
[junit4] 2> 945691 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting corePoolSize to: 0
[junit4] 2> 945691 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting maximumPoolSize to: 2147483647
[junit4] 2> 945691 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting maxThreadIdleTime to: 5
[junit4] 2> 945691 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting sizeOfQueue to: -1
[junit4] 2> 945692 T7678 oashc.HttpShardHandlerFactory.getParameter
Setting fairnessPolicy to: false
[junit4] 2> 945692 T7678 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 945692 T7678 oasl.LogWatcher.createWatcher SLF4J impl is
org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 945693 T7678 oasl.LogWatcher.newRegisteredLogWatcher
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 945693 T7678 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 945693 T7678 oasc.ZkContainer.initZooKeeper Zookeeper
client=127.0.0.1:10388/solr
[junit4] 2> 945693 T7678 oasc.ZkController.checkChrootPath zkHost includes
chroot
[junit4] 2> 945694 T7678 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 945696 T7743 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@2084180d
name:ZooKeeperConnection Watcher:127.0.0.1:10388 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 945696 T7678 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 945698 T7678 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 945699 T7745 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4bac19b6
name:ZooKeeperConnection Watcher:127.0.0.1:10388/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 945699 T7678 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 945703 T7678
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 946706 T7678 oasc.ZkController.createEphemeralLiveNode
Register node as live in ZooKeeper:/live_nodes/127.0.0.1:10410_
[junit4] 2> 946707 T7678 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1:10410_
[junit4] 2> 946717 T7747 oasc.ZkController.publish publishing
core=collection1 state=down collection=collection1
[junit4] 2> 946718 T7747 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 946719 T7713 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 946719 T7747 oasc.ZkController.waitForCoreNodeName look for
our core node name
[junit4] 2> 946719 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 946719 T7712 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 946720 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 946721 T7701 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:10410";,
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:10410_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 946721 T7701 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=2
[junit4] 2> 946721 T7701 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 946723 T7712 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 946724 T7712 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> 946724 T7711 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> 946724 T7746 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> 946724 T7727 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> 947719 T7747 oasc.ZkController.waitForShardId waiting to find
shard id in clusterstate for collection1
[junit4] 2> 947720 T7747 oasc.ZkController.createCollectionZkNode Check
for collection zkNode:collection1
[junit4] 2> 947721 T7747 oasc.ZkController.createCollectionZkNode
Collection zkNode exists
[junit4] 2> 947721 T7747 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/collection1
[junit4] 2> 947722 T7747 oascc.ZkStateReader.readConfigName
path=/collections/collection1 configName=conf1 specified config exists in
ZooKeeper
[junit4] 2> 947722 T7747 oasc.SolrResourceLoader.<init> new
SolrResourceLoader for directory:
'../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/collection1/'
[junit4] 2> 947724 T7747 oasc.SolrResourceLoader.replaceClassLoader Adding
'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/collection1/lib/classes/'
to classloader
[junit4] 2> 947725 T7747 oasc.SolrResourceLoader.replaceClassLoader Adding
'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/collection1/lib/README'
to classloader
[junit4] 2> 947726 T7747 oasc.SolrResourceLoader.replaceClassLoader Adding
'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/collection1/lib/.svn/'
to classloader
[junit4] 2> 947793 T7747 oasc.SolrConfig.<init> Using Lucene MatchVersion:
LUCENE_5_0
[junit4] 2> 947842 T7747 oasc.SolrConfig.<init> Loaded SolrConfig:
solrconfig.xml
[junit4] 2> 947943 T7747 oass.IndexSchema.readSchema Reading Solr Schema
from schema.xml
[junit4] 2> 947961 T7747 oass.IndexSchema.readSchema [collection1] Schema
name=test
[junit4] 2> 948371 T7747 oass.OpenExchangeRatesOrgProvider.init
Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 948385 T7747 oass.IndexSchema.readSchema default search field
in schema is text
[junit4] 2> 948388 T7747 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 948400 T7747 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 948405 T7747 oass.FileExchangeRateProvider.reload Reloading
exchange rates from file currency.xml
[junit4] 2> 948410 T7747 oass.OpenExchangeRatesOrgProvider.reload
Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 948410 T7747
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 948412 T7747
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 948412 T7747 oass.OpenExchangeRatesOrgProvider.reload
Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 948413 T7747
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 948413 T7747
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 948413 T7747 oasc.CoreContainer.create Creating SolrCore
'collection1' using configuration from collection collection1
[junit4] 2> 948413 T7747 oasc.SolrCore.initDirectoryFactory
org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 948414 T7747 oasc.SolrCore.<init> [collection1] Opening new
SolrCore at
../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/collection1/,
dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/collection1/data/
[junit4] 2> 948414 T7747 oasc.JmxMonitoredMap.<init> JMX monitoring is
enabled. Adding Solr mbeans to JMX Server:
com.sun.jmx.mbeanserver.JmxMBeanServer@185af219
[junit4] 2> 948415 T7747 oasc.CachingDirectoryFactory.get return new
directory for
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/collection1/data
[junit4] 2> 948415 T7747 oasc.SolrCore.getNewIndexDir New index directory
detected: old=null
new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/collection1/data/index/
[junit4] 2> 948416 T7747 oasc.SolrCore.initIndex WARN [collection1] Solr
index directory
'/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/collection1/data/index'
doesn't exist. Creating new index...
[junit4] 2> 948416 T7747 oasc.CachingDirectoryFactory.get return new
directory for
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-004/collection1/data/index
[junit4] 2> 948417 T7747 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.AlcoholicMergePolicy:
[AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1809299489,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 948418 T7747 oasc.SolrDeletionPolicy.onCommit
SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2>
commit{dir=MockDirectoryWrapper(RAMDirectory@38cf2402
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7c21bd8f),segFN=segments_1,generation=1}
[junit4] 2> 948418 T7747 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 948424 T7747 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "nodistrib"
[junit4] 2> 948424 T7747 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "dedupe"
[junit4] 2> 948424 T7747 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 948425 T7747 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "stored_sig"
[junit4] 2> 948425 T7747 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 948425 T7747 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 948426 T7747 oasup.UpdateRequestProcessorChain.init creating
updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 948426 T7747 oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 948426 T7747 oasc.SolrCore.loadUpdateProcessorChains no
updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 948427 T7747 oasc.RequestHandlers.initHandlersFromConfig
created standard: solr.StandardRequestHandler
[junit4] 2> 948428 T7747 oasc.RequestHandlers.initHandlersFromConfig
created /get: solr.RealTimeGetHandler
[junit4] 2> 948428 T7747 oasc.RequestHandlers.initHandlersFromConfig
adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 948428 T7747 oasc.RequestHandlers.initHandlersFromConfig
created /replication: solr.ReplicationHandler
[junit4] 2> 948429 T7747 oasc.RequestHandlers.initHandlersFromConfig
created /update: solr.UpdateRequestHandler
[junit4] 2> 948429 T7747 oasc.RequestHandlers.initHandlersFromConfig
created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 948430 T7747 oasc.RequestHandlers.initHandlersFromConfig
created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 948430 T7747 oasc.RequestHandlers.initHandlersFromConfig
created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 948452 T7747 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 948459 T7747 oasu.CommitTracker.<init> Hard AutoCommit:
disabled
[junit4] 2> 948459 T7747 oasu.CommitTracker.<init> Soft AutoCommit:
disabled
[junit4] 2> 948460 T7747 oasu.RandomMergePolicy.<init> RandomMergePolicy
wrapping class org.apache.lucene.index.LogByteSizeMergePolicy:
[LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=31,
maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807,
calibrateSizeByDeletes=false, maxMergeDocs=2147483647,
maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 948460 T7747 oasc.SolrDeletionPolicy.onInit
SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2>
commit{dir=MockDirectoryWrapper(RAMDirectory@38cf2402
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7c21bd8f),segFN=segments_1,generation=1}
[junit4] 2> 948461 T7747 oasc.SolrDeletionPolicy.updateCommits newest
commit generation = 1
[junit4] 2> 948461 T7747 oass.SolrIndexSearcher.<init> Opening
Searcher@7a18f2a[collection1] main
[junit4] 2> 948461 T7747 oascc.ZkStateReader.readConfigName Load
collection config from:/collections/collection1
[junit4] 2> 948462 T7747 oascc.ZkStateReader.readConfigName
path=/collections/collection1 configName=conf1 specified config exists in
ZooKeeper
[junit4] 2> 948462 T7747 oasr.ManagedResourceStorage.newStorageIO Setting
up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 948463 T7747
oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured
ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 948463 T7747 oasr.RestManager.init Initializing RestManager
with initArgs: {}
[junit4] 2> 948463 T7747 oasr.ManagedResourceStorage.load Reading
_rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 948464 T7747
oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes
from znode /configs/conf1/_rest_managed.json
[junit4] 2> 948464 T7747 oasr.ManagedResourceStorage.load Loaded
LinkedHashMap at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 948465 T7747 oasr.ManagedResource.reloadFromStorage Loaded
initArgs {} for /rest/managed
[junit4] 2> 948465 T7747 oasr.RestManager.init Initializing 0 registered
ManagedResources
[junit4] 2> 948469 T7748 oasc.SolrCore.registerSearcher [collection1]
Registered new searcher Searcher@7a18f2a[collection1]
main{UninvertingDirectoryReader()}
[junit4] 2> 948472 T7747 oasc.CoreContainer.registerCore registering core:
collection1
[junit4] 2> 948473 T7751 oasc.ZkController.register Register replica -
core:collection1 address:http://127.0.0.1:10410 collection:collection1
shard:shard2
[junit4] 2> 948473 T7678 oass.SolrDispatchFilter.init
user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4] 2> 948473 T7678 oass.SolrDispatchFilter.init
SolrDispatchFilter.init() done
[junit4] 2> 948474 T7751 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 948478 T7751 oasc.ShardLeaderElectionContext.runLeaderProcess
Running the leader process for shard shard2
[junit4] 2> 948479 T7712 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 948479 T7751
oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found
to continue.
[junit4] 2> 948480 T7751 oasc.ShardLeaderElectionContext.runLeaderProcess
I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C427 name=collection1
org.apache.solr.core.SolrCore@2922b606 url=http://127.0.0.1:10410/collection1
node=127.0.0.1:10410_ C427_STATE=coll:collection1 core:collection1
props:{state=down, base_url=http://127.0.0.1:10410, core=collection1,
node_name=127.0.0.1:10410_}
[junit4] 2> 948480 T7751 C427 P10410 oasc.SyncStrategy.sync Sync replicas
to http://127.0.0.1:10410/collection1/
[junit4] 2> 948480 T7751 C427 P10410 oasc.SyncStrategy.syncReplicas Sync
Success - now sync replicas to me
[junit4] 2> 948480 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 948480 T7751 C427 P10410 oasc.SyncStrategy.syncToMe
http://127.0.0.1:10410/collection1/ has no replicas
[junit4] 2> 948481 T7751 oasc.ShardLeaderElectionContext.runLeaderProcess
I am the new leader: http://127.0.0.1:10410/collection1/ shard2
[junit4] 2> 948481 T7751 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard2
[junit4] 2> 948482 T7712 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 948483 T7712 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> 948483 T7727 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> 948483 T7711 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> 948483 T7746 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> 948486 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 948488 T7712 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 948590 T7711 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> 948590 T7746 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> 948590 T7712 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> 948590 T7727 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> 948638 T7751 oasc.ZkController.register We are
http://127.0.0.1:10410/collection1/ and leader is
http://127.0.0.1:10410/collection1/
[junit4] 2> 948639 T7751 oasc.ZkController.register No LogReplay needed
for core=collection1 baseURL=http://127.0.0.1:10410
[junit4] 2> 948639 T7751 oasc.ZkController.checkRecovery I am the leader,
no recovery necessary
[junit4] 2> 948639 T7751 oasc.ZkController.publish publishing
core=collection1 state=active collection=collection1
[junit4] 2> 948639 T7751 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 948641 T7712 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 948641 T7713 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 948641 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 948641 T7751 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 948642 T7701 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 948643 T7701 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:10410";,
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:10410_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 948645 T7704 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 948747 T7704 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> 948747 T7727 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> 948747 T7711 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> 948747 T7746 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> 949877 T7678 oasc.AbstractFullDistribZkTestBase.createJettys
create jetty 3
[junit4] 2> 949878 T7678 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 949881 T7678 oejs.AbstractConnector.doStart Started
[email protected]:10419
[junit4] 2> 949882 T7678 oass.SolrDispatchFilter.init
SolrDispatchFilter.init()
[junit4] 2> 949882 T7678 oasc.SolrResourceLoader.locateSolrHome JNDI not
configured for solr (NoInitialContextEx)
[junit4] 2> 949882 T7678 oasc.SolrResourceLoader.locateSolrHome using
system property solr.solr.home:
../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-005
[junit4] 2> 949882 T7678 oasc.SolrResourceLoader.<init> new
SolrResourceLoader for directory:
'../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-005/'
[junit4] 2> 949918 T7678 oasc.ConfigSolr.fromFile Loading container
configuration from
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-005/solr.xml
[junit4] 2> 949977 T7678 oasc.CoreContainer.<init> New CoreContainer
1703024358
[junit4] 2> 949978 T7678 oasc.CoreContainer.load Loading cores into
CoreContainer
[instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/bu
[...truncated too long message...]
hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-006/ocptest3_shard1_replica1/data/index
[junit4] 2> 989966 T7678 oasc.SolrCore.close
[ocptest_shardsplit_shard2_replica1] CLOSING SolrCore
org.apache.solr.core.SolrCore@4f8648b2
[junit4] 2> 989974 T7678 oasu.DirectUpdateHandler2.close closing
DirectUpdateHandler2{commits=0,autocommits=0,soft
autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 989975 T7678 oasu.SolrCoreState.decrefSolrCoreState Closing
SolrCoreState
[junit4] 2> 989975 T7678 oasu.DefaultSolrCoreState.closeIndexWriter
SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 989975 T7678 oasu.DefaultSolrCoreState.closeIndexWriter
closing IndexWriter with IndexWriterCloser
[junit4] 2> 989976 T7678 oasc.SolrCore.closeSearcher
[ocptest_shardsplit_shard2_replica1] Closing main searcher on request.
[junit4] 2> 989976 T7678 oasc.CachingDirectoryFactory.close Closing
MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 989977 T7678 oasc.CachingDirectoryFactory.closeCacheValue
looking to close
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-006/ocptest_shardsplit_shard2_replica1/data
[CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-006/ocptest_shardsplit_shard2_replica1/data;done=false>>]
[junit4] 2> 989977 T7678 oasc.CachingDirectoryFactory.close Closing
directory:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-006/ocptest_shardsplit_shard2_replica1/data
[junit4] 2> 989977 T7678 oasc.CachingDirectoryFactory.closeCacheValue
looking to close
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-006/ocptest_shardsplit_shard2_replica1/data/index
[CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-006/ocptest_shardsplit_shard2_replica1/data/index;done=false>>]
[junit4] 2> 989978 T7678 oasc.CachingDirectoryFactory.close Closing
directory:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001/tempDir-006/ocptest_shardsplit_shard2_replica1/data/index
[junit4] 2> 989978 T9208 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:10431_
[junit4] 2> 989980 T7786 oascc.ZkStateReader$3.process WARN ZooKeeper
watch triggered, but Solr cannot talk to ZK
[junit4] 2> 989981 T9210
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 989982 T7678 oejsh.ContextHandler.doStop stopped
o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 994596 T7678 oas.SolrTestCaseJ4.tearDown ###Ending
testDistribSearch
[junit4] 2> 994599 T7678 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:10388 10388
[junit4] 2> 994686 T7679 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:10388 10388
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=MultiThreadedOCPTest -Dtests.method=testDistribSearch
-Dtests.seed=B2526CA8AF3CA5D1 -Dtests.multiplier=3 -Dtests.slow=true
-Dtests.locale=ko -Dtests.timezone=America/Puerto_Rico
-Dtests.file.encoding=UTF-8
[junit4] FAILURE 58.4s J1 | MultiThreadedOCPTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: We have a failed
SPLITSHARD task
[junit4] > at
__randomizedtesting.SeedInfo.seed([B2526CA8AF3CA5D1:33B4E2B0D863C5ED]:0)
[junit4] > at
org.apache.solr.cloud.MultiThreadedOCPTest.testTaskExclusivity(MultiThreadedOCPTest.java:125)
[junit4] > at
org.apache.solr.cloud.MultiThreadedOCPTest.doTest(MultiThreadedOCPTest.java:71)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 994701 T7678 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./temp/solr.cloud.MultiThreadedOCPTest-B2526CA8AF3CA5D1-001
[junit4] 2> 58380 T7677 ccr.ThreadLeakControl.checkThreadLeaks WARNING
Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Lucene49: {}, docValues:{},
sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=ko,
timezone=America/Puerto_Rico
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60
(64-bit)/cpus=16,threads=1,free=164516752,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [IndexSchemaRuntimeFieldTest,
DirectUpdateHandlerOptimizeTest, ZkSolrClientTest, BlockDirectoryTest,
TestElisionMultitermQuery, CSVRequestHandlerTest,
TestSerializedLuceneMatchVersion, ResourceLoaderTest, NoFacetTest,
TestPHPSerializedResponseWriter, TestSolr4Spatial2, TestRealTimeGet,
SolrPluginUtilsTest, TestCoreContainer, TestQueryUtils,
TestSolrQueryParserResource, TestConfigSets, TestNonDefinedSimilarityFactory,
ScriptEngineTest, SolrRequestParserTest, TestCollationField,
RequestHandlersTest, TestReversedWildcardFilterFactory,
TestDistributedGrouping, TestExtendedDismaxParser, DateRangeFieldTest,
SolrTestCaseJ4Test, TestValueSourceCache, AlternateDirectoryTest,
HdfsDirectoryTest, TestSuggestSpellingConverter, RemoteQueryErrorTest,
StressHdfsTest, AnalysisAfterCoreReloadTest, TestRestManager, TestOrdValues,
HttpPartitionTest, TestDistribDocBasedVersion, HdfsChaosMonkeySafeLeaderTest,
SortByFunctionTest, TestIndexSearcher, DeleteReplicaTest,
TestAtomicUpdateErrorCases, MultiTermTest, TestDocumentBuilder,
TestStressLucene, DistributedSuggestComponentTest, SimplePostToolTest,
DirectSolrConnectionTest, TestRandomFaceting, SolrInfoMBeanTest, TestLRUCache,
TestExpandComponent, HdfsUnloadDistributedZkTest, TermVectorComponentTest,
DistanceFunctionTest, TestCharFilters, UUIDUpdateProcessorFallbackTest,
TestZkChroot, TestXIncludeConfig, TestLazyCores, SoftAutoCommitTest,
TestCollectionAPI, MergeStrategyTest, TestBM25SimilarityFactory,
FieldFacetExtrasTest, FileBasedSpellCheckerTest,
CollectionsAPIDistributedZkTest, TestImplicitCoreProperties,
TestPerFieldSimilarity, CopyFieldTest, OutputWriterTest, SolrCoreTest,
TestManagedSchemaFieldResource, MultiThreadedOCPTest]
[junit4] Completed on J1 in 58.66s, 1 test, 1 failure <<< FAILURES!
[...truncated 842 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:467:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:447:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:45:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/extra-targets.xml:37:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:189:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:496:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1298:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:922:
There were test failures: 422 suites, 1754 tests, 1 failure, 53 ignored (19
assumptions)
Total time: 110 minutes 22 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-Tests-trunk-Java7 #4781
Archived 3 artifacts
Archive block size is 32768
Received 0 blocks and 193858568 bytes
Compression is 0.0%
Took 32 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
