Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/2247/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED:
org.apache.solr.cloud.CollectionsAPIAsyncDistributedZkTest.testSolrJAPICalls
Error Message:
Shard split did not complete. Last recorded state: running
expected:<[completed]> but was:<[running]>
Stack Trace:
org.junit.ComparisonFailure: Shard split did not complete. Last recorded state:
running expected:<[completed]> but was:<[running]>
at
__randomizedtesting.SeedInfo.seed([6C4EE8531FF12691:342A6432199B8E45]:0)
at org.junit.Assert.assertEquals(Assert.java:125)
at
org.apache.solr.cloud.CollectionsAPIAsyncDistributedZkTest.testSolrJAPICalls(CollectionsAPIAsyncDistributedZkTest.java:101)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
at
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:960)
at
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
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:845)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
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:54)
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 9362 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIAsyncDistributedZkTest
[junit4] 2> Creating dataDir:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/init-core-data-001
[junit4] 2> 109315 T411 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl
(false) and clientAuth (false)
[junit4] 2> 109315 T411 oas.BaseDistributedSearchTestCase.initHostContext
Setting hostContext system property: /_rv/
[junit4] 2> 109339 T411 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 109339 T412 oasc.ZkTestServer$2$1.setClientPort client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 109339 T412 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 109342 T411 oasc.ZkTestServer.run start zk server on port:59629
[junit4] 2> 109343 T411
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 109345 T411 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 109368 T419 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5736238c
name:ZooKeeperConnection Watcher:127.0.0.1:59629 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 109370 T411 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 109370 T411 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 109370 T411 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 109406 T411
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 109418 T411 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 109420 T422 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@6bae3c21
name:ZooKeeperConnection Watcher:127.0.0.1:59629/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 109431 T411 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 109432 T411 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 109432 T411 oascc.SolrZkClient.makePath makePath:
/collections/collection1
[junit4] 2> 109462 T411 oascc.SolrZkClient.makePath makePath:
/collections/collection1/shards
[junit4] 2> 109471 T411 oascc.SolrZkClient.makePath makePath:
/collections/control_collection
[junit4] 2> 109475 T411 oascc.SolrZkClient.makePath makePath:
/collections/control_collection/shards
[junit4] 2> 109485 T411 oasc.AbstractZkTestCase.putConfig put
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml
to /configs/conf1/solrconfig.xml
[junit4] 2> 109485 T411 oascc.SolrZkClient.makePath makePath:
/configs/conf1/solrconfig.xml
[junit4] 2> 109494 T411 oasc.AbstractZkTestCase.putConfig put
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml
to /configs/conf1/schema.xml
[junit4] 2> 109495 T411 oascc.SolrZkClient.makePath makePath:
/configs/conf1/schema.xml
[junit4] 2> 109502 T411 oasc.AbstractZkTestCase.putConfig put
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml
to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 109503 T411 oascc.SolrZkClient.makePath makePath:
/configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 109510 T411 oasc.AbstractZkTestCase.putConfig put
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt
to /configs/conf1/stopwords.txt
[junit4] 2> 109511 T411 oascc.SolrZkClient.makePath makePath:
/configs/conf1/stopwords.txt
[junit4] 2> 109517 T411 oasc.AbstractZkTestCase.putConfig put
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt
to /configs/conf1/protwords.txt
[junit4] 2> 109518 T411 oascc.SolrZkClient.makePath makePath:
/configs/conf1/protwords.txt
[junit4] 2> 109523 T411 oasc.AbstractZkTestCase.putConfig put
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml
to /configs/conf1/currency.xml
[junit4] 2> 109523 T411 oascc.SolrZkClient.makePath makePath:
/configs/conf1/currency.xml
[junit4] 2> 109529 T411 oasc.AbstractZkTestCase.putConfig put
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml
to /configs/conf1/enumsConfig.xml
[junit4] 2> 109529 T411 oascc.SolrZkClient.makePath makePath:
/configs/conf1/enumsConfig.xml
[junit4] 2> 109536 T411 oasc.AbstractZkTestCase.putConfig put
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json
to /configs/conf1/open-exchange-rates.json
[junit4] 2> 109537 T411 oascc.SolrZkClient.makePath makePath:
/configs/conf1/open-exchange-rates.json
[junit4] 2> 109545 T411 oasc.AbstractZkTestCase.putConfig put
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt
to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 109545 T411 oascc.SolrZkClient.makePath makePath:
/configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 109552 T411 oasc.AbstractZkTestCase.putConfig put
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt
to /configs/conf1/old_synonyms.txt
[junit4] 2> 109552 T411 oascc.SolrZkClient.makePath makePath:
/configs/conf1/old_synonyms.txt
[junit4] 2> 109558 T411 oasc.AbstractZkTestCase.putConfig put
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt
to /configs/conf1/synonyms.txt
[junit4] 2> 109558 T411 oascc.SolrZkClient.makePath makePath:
/configs/conf1/synonyms.txt
[junit4] 2> 109963 T411 oas.SolrTestCaseJ4.writeCoreProperties Writing
core.properties file to
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores/collection1
[junit4] 2> 109967 T411 oejs.Server.doStart jetty-9.2.10.v20150310
[junit4] 2> 109973 T411 oejsh.ContextHandler.doStart Started
o.e.j.s.ServletContextHandler@72320762{/_rv,null,AVAILABLE}
[junit4] 2> 109978 T411 oejs.AbstractConnector.doStart Started
ServerConnector@18fffa30{HTTP/1.1}{127.0.0.1:59632}
[junit4] 2> 109978 T411 oejs.Server.doStart Started @114238ms
[junit4] 2> 109978 T411 oascse.JettySolrRunner$1.lifeCycleStarted Jetty
properties: {hostContext=/_rv, hostPort=59632,
coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores}
[junit4] 2> 109979 T411 oass.SolrDispatchFilter.init
SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@74a14482
[junit4] 2> 109979 T411 oasc.SolrResourceLoader.<init> new
SolrResourceLoader for directory:
'/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/'
[junit4] 2> 110013 T411 oasc.SolrXmlConfig.fromFile Loading container
configuration from
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/solr.xml
[junit4] 2> 110024 T411 oasc.CorePropertiesLocator.<init> Config-defined
core root directory:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores
[junit4] 2> 110024 T411 oasc.CoreContainer.<init> New CoreContainer
1387033201
[junit4] 2> 110024 T411 oasc.CoreContainer.load Loading cores into
CoreContainer
[instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/]
[junit4] 2> 110024 T411 oasc.CoreContainer.load loading shared library:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/lib
[junit4] 2> 110025 T411 oasc.SolrResourceLoader.addToClassLoader WARN
Can't find (or read) directory to add to classloader: lib (resolved as:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/lib).
[junit4] 2> 110038 T411 oashc.HttpShardHandlerFactory.init created with
socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost :
20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize :
2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy :
false,useRetries : false,
[junit4] 2> 110043 T411 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 110044 T411 oasl.LogWatcher.createWatcher SLF4J impl is
org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 110044 T411 oasl.LogWatcher.newRegisteredLogWatcher
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 110044 T411 oasc.CoreContainer.load Node Name: 127.0.0.1
[junit4] 2> 110045 T411 oasc.ZkContainer.initZooKeeper Zookeeper
client=127.0.0.1:59629/solr
[junit4] 2> 110045 T411 oasc.ZkController.checkChrootPath zkHost includes
chroot
[junit4] 2> 110045 T411
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 110052 T411 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 110064 T436 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@41c5d93c
name:ZooKeeperConnection Watcher:127.0.0.1:59629 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 110067 T411 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 110067 T411 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 110110 T411 n:127.0.0.1:59632__rv
oascc.ConnectionManager.waitForConnected Waiting for client to connect to
ZooKeeper
[junit4] 2> 110114 T439 n:127.0.0.1:59632__rv
oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4026fc9e
name:ZooKeeperConnection Watcher:127.0.0.1:59629/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 110114 T411 n:127.0.0.1:59632__rv
oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 110122 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /overseer/queue
[junit4] 2> 110152 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /overseer/collection-queue-work
[junit4] 2> 110166 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /overseer/collection-map-running
[junit4] 2> 110175 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /overseer/collection-map-completed
[junit4] 2> 110187 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /overseer/collection-map-failure
[junit4] 2> 110206 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /live_nodes
[junit4] 2> 110213 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /aliases.json
[junit4] 2> 110220 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /clusterstate.json
[junit4] 2> 110224 T411 n:127.0.0.1:59632__rv
oasc.ZkController.createEphemeralLiveNode Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:59632__rv
[junit4] 2> 110228 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /live_nodes/127.0.0.1:59632__rv
[junit4] 2> 110251 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /overseer_elect
[junit4] 2> 110254 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /overseer_elect/election
[junit4] 2> 110258 T411 n:127.0.0.1:59632__rv oasc.Overseer.close Overseer
(id=null) closing
[junit4] 2> 110261 T411 n:127.0.0.1:59632__rv
oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader
127.0.0.1:59632__rv
[junit4] 2> 110261 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /overseer_elect/leader
[junit4] 2> 110265 T411 n:127.0.0.1:59632__rv oasc.Overseer.start Overseer
(id=93748106075373571-127.0.0.1:59632__rv-n_0000000000) starting
[junit4] 2> 110270 T411 n:127.0.0.1:59632__rv oascc.SolrZkClient.makePath
makePath: /overseer/queue-work
[junit4] 2> 110287 T411 n:127.0.0.1:59632__rv
oasc.OverseerAutoReplicaFailoverThread.<init> Starting
OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 110289 T441 n:127.0.0.1:59632__rv
oasc.OverseerCollectionProcessor.run Process current queue of collection
creations
[junit4] 2> 110290 T411 n:127.0.0.1:59632__rv
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 110290 T440 n:127.0.0.1:59632__rv
oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 110302 T411 n:127.0.0.1:59632__rv
oasc.CorePropertiesLocator.discover Looking for core definitions underneath
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores
[junit4] 2> 110305 T411 n:127.0.0.1:59632__rv oasc.CoreDescriptor.<init>
CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false,
schema=schema.xml, loadOnStartup=true,
instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores/collection1,
collection=control_collection,
absoluteInstDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores/collection1/, coreNodeName=,
dataDir=data/, shard=}
[junit4] 2> 110305 T411 n:127.0.0.1:59632__rv
oasc.CorePropertiesLocator.discoverUnder Found core collection1 in
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores/collection1/
[junit4] 2> 110305 T411 n:127.0.0.1:59632__rv
oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 110310 T443 n:127.0.0.1:59632__rv c:control_collection
x:collection1 oasc.ZkController.publish publishing core=collection1 state=down
collection=control_collection
[junit4] 2> 110311 T443 n:127.0.0.1:59632__rv c:control_collection
x:collection1 oasc.ZkController.publish numShards not found on descriptor -
reading it from system property
[junit4] 2> 110313 T443 n:127.0.0.1:59632__rv
oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 110320 T440 n:127.0.0.1:59632__rv
oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59632/_rv";,
[junit4] 2> "node_name":"127.0.0.1:59632__rv",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 110321 T440 n:127.0.0.1:59632__rv
oasco.ReplicaMutator.updateState Update state numShards=1 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59632/_rv";,
[junit4] 2> "node_name":"127.0.0.1:59632__rv",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 110322 T440 n:127.0.0.1:59632__rv
oasco.ClusterStateMutator.createCollection building a new cName:
control_collection
[junit4] 2> 110322 T440 n:127.0.0.1:59632__rv
oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
[junit4] 2> 110325 T439 n:127.0.0.1:59632__rv
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> 110334 T439 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/queue state SyncConnected
[junit4] 2> 111315 T443 n:127.0.0.1:59632__rv
oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for
collection1
[junit4] 2> 111315 T443 n:127.0.0.1:59632__rv
oasc.ZkController.createCollectionZkNode Check for collection
zkNode:control_collection
[junit4] 2> 111317 T443 n:127.0.0.1:59632__rv
oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 111317 T443 n:127.0.0.1:59632__rv
oascc.ZkStateReader.readConfigName Load collection config
from:/collections/control_collection
[junit4] 2> 111321 T443 n:127.0.0.1:59632__rv
oascc.ZkStateReader.readConfigName path=/collections/control_collection
configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 111322 T443 n:127.0.0.1:59632__rv
oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory:
'/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores/collection1/'
[junit4] 2> 111349 T443 n:127.0.0.1:59632__rv oasc.Config.<init> loaded
config solrconfig.xml with version 0
[junit4] 2> 111366 T443 n:127.0.0.1:59632__rv
oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
[junit4] 2> 111368 T443 n:127.0.0.1:59632__rv oasc.SolrConfig.<init> Using
Lucene MatchVersion: 6.0.0
[junit4] 2> 111385 T443 n:127.0.0.1:59632__rv oasc.SolrConfig.<init>
Loaded SolrConfig: solrconfig.xml
[junit4] 2> 111387 T443 n:127.0.0.1:59632__rv oass.IndexSchema.readSchema
Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 111392 T443 n:127.0.0.1:59632__rv oass.IndexSchema.readSchema
[collection1] Schema name=test
[junit4] 2> 111466 T443 n:127.0.0.1:59632__rv
oass.OpenExchangeRatesOrgProvider.init Initialized with
rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 111475 T443 n:127.0.0.1:59632__rv oass.IndexSchema.readSchema
default search field in schema is text
[junit4] 2> 111476 T443 n:127.0.0.1:59632__rv oass.IndexSchema.readSchema
unique key field: id
[junit4] 2> 111577 T443 n:127.0.0.1:59632__rv
oass.FileExchangeRateProvider.reload Reloading exchange rates from file
currency.xml
[junit4] 2> 111581 T443 n:127.0.0.1:59632__rv
oass.FileExchangeRateProvider.reload Reloading exchange rates from file
currency.xml
[junit4] 2> 111583 T443 n:127.0.0.1:59632__rv
oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from
open-exchange-rates.json
[junit4] 2> 111586 T443 n:127.0.0.1:59632__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 111586 T443 n:127.0.0.1:59632__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 111586 T443 n:127.0.0.1:59632__rv
oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from
open-exchange-rates.json
[junit4] 2> 111598 T443 n:127.0.0.1:59632__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 111600 T443 n:127.0.0.1:59632__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 111600 T443 n:127.0.0.1:59632__rv oasc.CoreContainer.create
Creating SolrCore 'collection1' using configuration from collection
control_collection
[junit4] 2> 111600 T443 n:127.0.0.1:59632__rv x:collection1
oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 111601 T443 n:127.0.0.1:59632__rv x:collection1
oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores/collection1/], dataDir=[null]
[junit4] 2> 111601 T443 n:127.0.0.1:59632__rv x:collection1
oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to
JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@32034f3
[junit4] 2> 111601 T443 n:127.0.0.1:59632__rv x:collection1
oasc.CachingDirectoryFactory.get return new directory for
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores/collection1/data
[junit4] 2> 111602 T443 n:127.0.0.1:59632__rv x:collection1
oasc.SolrCore.getNewIndexDir New index directory detected: old=null
new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores/collection1/data/index/
[junit4] 2> 111602 T443 n:127.0.0.1:59632__rv x:collection1
oasc.SolrCore.initIndex WARN [collection1] Solr index directory
'/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores/collection1/data/index' doesn't exist.
Creating new index...
[junit4] 2> 111602 T443 n:127.0.0.1:59632__rv x:collection1
oasc.CachingDirectoryFactory.get return new directory for
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/control-001/cores/collection1/data/index
[junit4] 2> 111602 T443 n:127.0.0.1:59632__rv x:collection1
oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy:
minMergeSize=1000, mergeFactor=41, maxMergeSize=9223372036854775807,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=1.0]
[junit4] 2> 111603 T443 n:127.0.0.1:59632__rv x:collection1
oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2>
commit{dir=MockDirectoryWrapper(RAMDirectory@6f4b184c
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@56956477),segFN=segments_1,generation=1}
[junit4] 2> 111603 T443 n:127.0.0.1:59632__rv x:collection1
oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 111609 T443 n:127.0.0.1:59632__rv x:collection1
oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain
"nodistrib"
[junit4] 2> 111610 T443 n:127.0.0.1:59632__rv x:collection1
oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain
"dedupe"
[junit4] 2> 111610 T443 n:127.0.0.1:59632__rv x:collection1
oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 111610 T443 n:127.0.0.1:59632__rv x:collection1
oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain
"stored_sig"
[junit4] 2> 111610 T443 n:127.0.0.1:59632__rv x:collection1
oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 111610 T443 n:127.0.0.1:59632__rv x:collection1
oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain
"distrib-dup-test-chain-explicit"
[junit4] 2> 111611 T443 n:127.0.0.1:59632__rv x:collection1
oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 111611 T443 n:127.0.0.1:59632__rv x:collection1
oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 111611 T443 n:127.0.0.1:59632__rv x:collection1
oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined
as default, creating implicit default
[junit4] 2> 111620 T443 n:127.0.0.1:59632__rv x:collection1
oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 111622 T443 n:127.0.0.1:59632__rv x:collection1
oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 111624 T443 n:127.0.0.1:59632__rv x:collection1
oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 111625 T443 n:127.0.0.1:59632__rv x:collection1
oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 111632 T443 n:127.0.0.1:59632__rv x:collection1
oasc.RequestHandlers.initHandlersFromConfig Registered paths:
/admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/update,/admin/file
[junit4] 2> 111632 T443 n:127.0.0.1:59632__rv x:collection1
oasc.SolrCore.initStatsCache Using default statsCache cache:
org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 111634 T443 n:127.0.0.1:59632__rv x:collection1
oasu.UpdateHandler.<init> Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 111634 T443 n:127.0.0.1:59632__rv x:collection1
oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10
[junit4] 2> 111636 T443 n:127.0.0.1:59632__rv x:collection1
oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 111636 T443 n:127.0.0.1:59632__rv x:collection1
oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 111637 T443 n:127.0.0.1:59632__rv x:collection1
oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy:
minMergeSize=1000, mergeFactor=25, maxMergeSize=9223372036854775807,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.0]
[junit4] 2> 111637 T443 n:127.0.0.1:59632__rv x:collection1
oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2>
commit{dir=MockDirectoryWrapper(RAMDirectory@6f4b184c
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@56956477),segFN=segments_1,generation=1}
[junit4] 2> 111637 T443 n:127.0.0.1:59632__rv x:collection1
oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 111638 T443 n:127.0.0.1:59632__rv x:collection1
oass.SolrIndexSearcher.<init> Opening Searcher@8434080[collection1] main
[junit4] 2> 111638 T443 n:127.0.0.1:59632__rv x:collection1
oascc.ZkStateReader.readConfigName Load collection config
from:/collections/control_collection
[junit4] 2> 111641 T443 n:127.0.0.1:59632__rv x:collection1
oascc.ZkStateReader.readConfigName path=/collections/control_collection
configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 111642 T443 n:127.0.0.1:59632__rv x:collection1
oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for
the RestManager with znodeBase: /configs/conf1
[junit4] 2> 111643 T443 n:127.0.0.1:59632__rv x:collection1
oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured
ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 111643 T443 n:127.0.0.1:59632__rv x:collection1
oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 111643 T443 n:127.0.0.1:59632__rv x:collection1
oasr.ManagedResourceStorage.load Reading _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 111645 T443 n:127.0.0.1:59632__rv x:collection1
oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found
for znode /configs/conf1/_rest_managed.json
[junit4] 2> 111645 T443 n:127.0.0.1:59632__rv x:collection1
oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 111645 T443 n:127.0.0.1:59632__rv x:collection1
oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 111646 T443 n:127.0.0.1:59632__rv x:collection1
oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 111646 T444 n:127.0.0.1:59632__rv x:collection1
oasc.SolrCore.registerSearcher [collection1] Registered new searcher
Searcher@8434080[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 111647 T443 n:127.0.0.1:59632__rv x:collection1
oasc.ZkController.getConfDirListeners watch zkdir /configs/conf1
[junit4] 2> 111648 T443 n:127.0.0.1:59632__rv x:collection1
oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 111649 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oasc.ZkController.register Register replica -
core:collection1 address:http://127.0.0.1:59632/_rv
collection:control_collection shard:shard1
[junit4] 2> 111654 T411 n:127.0.0.1:59632__rv oass.SolrDispatchFilter.init
user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1
[junit4] 2> 111654 T411 n:127.0.0.1:59632__rv oass.SolrDispatchFilter.init
SolrDispatchFilter.init() done
[junit4] 2> 111656 T411
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 111657 T411 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 111662 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oascc.SolrZkClient.makePath makePath:
/collections/control_collection/leader_elect/shard1/election
[junit4] 2> 111663 T450 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3307c311
name:ZooKeeperConnection Watcher:127.0.0.1:59629/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 111664 T411 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 111664 T411 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 111664 T411
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 111676 T411 oasc.ChaosMonkey.monkeyLog monkey: init - expire
sessions:false cause connection loss:false
[junit4] 2> 111706 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess Running
the leader process for shard shard1
[junit4] 2> 111712 T439 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/queue state SyncConnected
[junit4] 2> 111719 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp
Enough replicas found to continue.
[junit4] 2> 111719 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I may
be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C84 name=collection1
org.apache.solr.core.SolrCore@48d41598
url=http://127.0.0.1:59632/_rv/collection1 node=127.0.0.1:59632__rv
C84_STATE=coll:control_collection core:collection1 props:{core=collection1,
base_url=http://127.0.0.1:59632/_rv, node_name=127.0.0.1:59632__rv, state=down}
[junit4] 2> 111719 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 C84 oasc.SyncStrategy.sync Sync replicas to
http://127.0.0.1:59632/_rv/collection1/
[junit4] 2> 111727 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 C84 oasc.SyncStrategy.syncReplicas Sync Success - now
sync replicas to me
[junit4] 2> 111727 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 C84 oasc.SyncStrategy.syncToMe
http://127.0.0.1:59632/_rv/collection1/ has no replicas
[junit4] 2> 111727 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I am
the new leader: http://127.0.0.1:59632/_rv/collection1/ shard1
[junit4] 2> 111727 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oascc.SolrZkClient.makePath makePath:
/collections/control_collection/leaders/shard1
[junit4] 2> 111729 T440 n:127.0.0.1:59632__rv
oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection"} current state
version: 1
[junit4] 2> 111751 T439 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/queue state SyncConnected
[junit4] 2> 111771 T440 n:127.0.0.1:59632__rv
oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "base_url":"http://127.0.0.1:59632/_rv";,
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 111916 T439 n:127.0.0.1:59632__rv
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> 111916 T450 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> 111970 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oasc.ZkController.register We are
http://127.0.0.1:59632/_rv/collection1/ and leader is
http://127.0.0.1:59632/_rv/collection1/
[junit4] 2> 111971 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oasc.ZkController.register No LogReplay needed for
core=collection1 baseURL=http://127.0.0.1:59632/_rv
[junit4] 2> 111971 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oasc.ZkController.checkRecovery I am the leader, no
recovery necessary
[junit4] 2> 111974 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oasc.ZkController.publish publishing core=collection1
state=active collection=control_collection
[junit4] 2> 111974 T447 n:127.0.0.1:59632__rv c:control_collection
s:shard1 x:collection1 oasc.ZkController.publish numShards not found on
descriptor - reading it from system property
[junit4] 2> 111982 T439 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/queue state SyncConnected
[junit4] 2> 111993 T440 n:127.0.0.1:59632__rv
oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59632/_rv";,
[junit4] 2> "node_name":"127.0.0.1:59632__rv",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"} current state version: 2
[junit4] 2> 111999 T440 n:127.0.0.1:59632__rv
oasco.ReplicaMutator.updateState Update state numShards=1 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59632/_rv";,
[junit4] 2> "node_name":"127.0.0.1:59632__rv",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 112110 T450 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> 112112 T439 n:127.0.0.1:59632__rv
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> 112205 T411 oas.SolrTestCaseJ4.writeCoreProperties Writing
core.properties file to
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/collection1
[junit4] 2> 112208 T411 oasc.AbstractFullDistribZkTestBase.createJettys
create jetty 1 in directory
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001
[junit4] 2> 112210 T411 oejs.Server.doStart jetty-9.2.10.v20150310
[junit4] 2> 112217 T411 oejsh.ContextHandler.doStart Started
o.e.j.s.ServletContextHandler@3b4b9605{/_rv,null,AVAILABLE}
[junit4] 2> 112220 T411 oejs.AbstractConnector.doStart Started
ServerConnector@294784ca{HTTP/1.1}{127.0.0.1:59636}
[junit4] 2> 112221 T411 oejs.Server.doStart Started @116479ms
[junit4] 2> 112221 T411 oascse.JettySolrRunner$1.lifeCycleStarted Jetty
properties: {solrconfig=solrconfig.xml, hostContext=/_rv, hostPort=59636,
coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores}
[junit4] 2> 112222 T411 oass.SolrDispatchFilter.init
SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@74a14482
[junit4] 2> 112222 T411 oasc.SolrResourceLoader.<init> new
SolrResourceLoader for directory:
'/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/'
[junit4] 2> 112257 T411 oasc.SolrXmlConfig.fromFile Loading container
configuration from
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/solr.xml
[junit4] 2> 112277 T411 oasc.CorePropertiesLocator.<init> Config-defined
core root directory:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores
[junit4] 2> 112277 T411 oasc.CoreContainer.<init> New CoreContainer
433359543
[junit4] 2> 112277 T411 oasc.CoreContainer.load Loading cores into
CoreContainer
[instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/]
[junit4] 2> 112277 T411 oasc.CoreContainer.load loading shared library:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/lib
[junit4] 2> 112279 T411 oasc.SolrResourceLoader.addToClassLoader WARN
Can't find (or read) directory to add to classloader: lib (resolved as:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/lib).
[junit4] 2> 112295 T411 oashc.HttpShardHandlerFactory.init created with
socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost :
20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize :
2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy :
false,useRetries : false,
[junit4] 2> 112300 T411 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params:
socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 112301 T411 oasl.LogWatcher.createWatcher SLF4J impl is
org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 112302 T411 oasl.LogWatcher.newRegisteredLogWatcher
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 112302 T411 oasc.CoreContainer.load Node Name: 127.0.0.1
[junit4] 2> 112303 T411 oasc.ZkContainer.initZooKeeper Zookeeper
client=127.0.0.1:59629/solr
[junit4] 2> 112303 T411 oasc.ZkController.checkChrootPath zkHost includes
chroot
[junit4] 2> 112303 T411
oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default
ZkCredentialsProvider
[junit4] 2> 112305 T411 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 112308 T464 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3b557282
name:ZooKeeperConnection Watcher:127.0.0.1:59629 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 112309 T411 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 112309 T411 oascc.SolrZkClient.createZkACLProvider Using
default ZkACLProvider
[junit4] 2> 112314 T411 n:127.0.0.1:59636__rv
oascc.ConnectionManager.waitForConnected Waiting for client to connect to
ZooKeeper
[junit4] 2> 112317 T467 n:127.0.0.1:59636__rv
oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@23a4075b
name:ZooKeeperConnection Watcher:127.0.0.1:59629/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 112317 T411 n:127.0.0.1:59636__rv
oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 112328 T411 n:127.0.0.1:59636__rv
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 113342 T411 n:127.0.0.1:59636__rv
oasc.ZkController.createEphemeralLiveNode Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:59636__rv
[junit4] 2> 113343 T411 n:127.0.0.1:59636__rv oascc.SolrZkClient.makePath
makePath: /live_nodes/127.0.0.1:59636__rv
[junit4] 2> 113352 T411 n:127.0.0.1:59636__rv oasc.Overseer.close Overseer
(id=null) closing
[junit4] 2> 113357 T411 n:127.0.0.1:59636__rv
oasc.CorePropertiesLocator.discover Looking for core definitions underneath
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores
[junit4] 2> 113359 T411 n:127.0.0.1:59636__rv oasc.CoreDescriptor.<init>
CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false,
schema=schema.xml, loadOnStartup=true,
instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/collection1, collection=collection1,
absoluteInstDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/collection1/, coreNodeName=,
dataDir=data/, shard=}
[junit4] 2> 113360 T411 n:127.0.0.1:59636__rv
oasc.CorePropertiesLocator.discoverUnder Found core collection1 in
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/collection1/
[junit4] 2> 113360 T411 n:127.0.0.1:59636__rv
oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 113363 T468 n:127.0.0.1:59636__rv c:collection1 x:collection1
oasc.ZkController.publish publishing core=collection1 state=down
collection=collection1
[junit4] 2> 113363 T468 n:127.0.0.1:59636__rv c:collection1 x:collection1
oasc.ZkController.publish numShards not found on descriptor - reading it from
system property
[junit4] 2> 113365 T468 n:127.0.0.1:59636__rv
oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 113365 T439 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/queue state SyncConnected
[junit4] 2> 113368 T440 n:127.0.0.1:59632__rv
oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59636/_rv";,
[junit4] 2> "node_name":"127.0.0.1:59636__rv",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"} current state version: 3
[junit4] 2> 113369 T440 n:127.0.0.1:59632__rv
oasco.ReplicaMutator.updateState Update state numShards=1 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59636/_rv";,
[junit4] 2> "node_name":"127.0.0.1:59636__rv",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 113370 T440 n:127.0.0.1:59632__rv
oasco.ClusterStateMutator.createCollection building a new cName: collection1
[junit4] 2> 113370 T440 n:127.0.0.1:59632__rv
oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
[junit4] 2> 113476 T439 n:127.0.0.1:59632__rv
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> 113476 T450 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> 113484 T467 n:127.0.0.1:59636__rv
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> 114367 T468 n:127.0.0.1:59636__rv
oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for
collection1
[junit4] 2> 114367 T468 n:127.0.0.1:59636__rv
oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 114368 T468 n:127.0.0.1:59636__rv
oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 114368 T468 n:127.0.0.1:59636__rv
oascc.ZkStateReader.readConfigName Load collection config
from:/collections/collection1
[junit4] 2> 114370 T468 n:127.0.0.1:59636__rv
oascc.ZkStateReader.readConfigName path=/collections/collection1
configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 114371 T468 n:127.0.0.1:59636__rv
oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory:
'/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/collection1/'
[junit4] 2> 114390 T468 n:127.0.0.1:59636__rv oasc.Config.<init> loaded
config solrconfig.xml with version 0
[junit4] 2> 114399 T468 n:127.0.0.1:59636__rv
oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
[junit4] 2> 114402 T468 n:127.0.0.1:59636__rv oasc.SolrConfig.<init> Using
Lucene MatchVersion: 6.0.0
[junit4] 2> 114410 T468 n:127.0.0.1:59636__rv oasc.SolrConfig.<init>
Loaded SolrConfig: solrconfig.xml
[junit4] 2> 114413 T468 n:127.0.0.1:59636__rv oass.IndexSchema.readSchema
Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 114418 T468 n:127.0.0.1:59636__rv oass.IndexSchema.readSchema
[collection1] Schema name=test
[junit4] 2> 114498 T468 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider.init Initialized with
rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 114512 T468 n:127.0.0.1:59636__rv oass.IndexSchema.readSchema
default search field in schema is text
[junit4] 2> 114514 T468 n:127.0.0.1:59636__rv oass.IndexSchema.readSchema
unique key field: id
[junit4] 2> 114600 T468 n:127.0.0.1:59636__rv
oass.FileExchangeRateProvider.reload Reloading exchange rates from file
currency.xml
[junit4] 2> 114603 T468 n:127.0.0.1:59636__rv
oass.FileExchangeRateProvider.reload Reloading exchange rates from file
currency.xml
[junit4] 2> 114610 T468 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from
open-exchange-rates.json
[junit4] 2> 114613 T468 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 114613 T468 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 114613 T468 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from
open-exchange-rates.json
[junit4] 2> 114615 T468 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 114616 T468 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 114616 T468 n:127.0.0.1:59636__rv oasc.CoreContainer.create
Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 114616 T468 n:127.0.0.1:59636__rv x:collection1
oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 114616 T468 n:127.0.0.1:59636__rv x:collection1
oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/collection1/], dataDir=[null]
[junit4] 2> 114616 T468 n:127.0.0.1:59636__rv x:collection1
oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to
JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@32034f3
[junit4] 2> 114617 T468 n:127.0.0.1:59636__rv x:collection1
oasc.CachingDirectoryFactory.get return new directory for
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/collection1/data
[junit4] 2> 114617 T468 n:127.0.0.1:59636__rv x:collection1
oasc.SolrCore.getNewIndexDir New index directory detected: old=null
new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/collection1/data/index/
[junit4] 2> 114617 T468 n:127.0.0.1:59636__rv x:collection1
oasc.SolrCore.initIndex WARN [collection1] Solr index directory
'/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/collection1/data/index' doesn't exist.
Creating new index...
[junit4] 2> 114618 T468 n:127.0.0.1:59636__rv x:collection1
oasc.CachingDirectoryFactory.get return new directory for
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/collection1/data/index
[junit4] 2> 114618 T468 n:127.0.0.1:59636__rv x:collection1
oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy:
minMergeSize=1000, mergeFactor=41, maxMergeSize=9223372036854775807,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=1.0]
[junit4] 2> 114619 T468 n:127.0.0.1:59636__rv x:collection1
oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2>
commit{dir=MockDirectoryWrapper(RAMDirectory@244c3e72
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1807099b),segFN=segments_1,generation=1}
[junit4] 2> 114619 T468 n:127.0.0.1:59636__rv x:collection1
oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 114626 T468 n:127.0.0.1:59636__rv x:collection1
oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain
"nodistrib"
[junit4] 2> 114626 T468 n:127.0.0.1:59636__rv x:collection1
oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain
"dedupe"
[junit4] 2> 114626 T468 n:127.0.0.1:59636__rv x:collection1
oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 114626 T468 n:127.0.0.1:59636__rv x:collection1
oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain
"stored_sig"
[junit4] 2> 114627 T468 n:127.0.0.1:59636__rv x:collection1
oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 114627 T468 n:127.0.0.1:59636__rv x:collection1
oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain
"distrib-dup-test-chain-explicit"
[junit4] 2> 114627 T468 n:127.0.0.1:59636__rv x:collection1
oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 114627 T468 n:127.0.0.1:59636__rv x:collection1
oasup.UpdateRequestProcessorChain.init inserting
DistributedUpdateProcessorFactory into updateRequestProcessorChain
"distrib-dup-test-chain-implicit"
[junit4] 2> 114628 T468 n:127.0.0.1:59636__rv x:collection1
oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined
as default, creating implicit default
[junit4] 2> 114633 T468 n:127.0.0.1:59636__rv x:collection1
oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 114635 T468 n:127.0.0.1:59636__rv x:collection1
oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 114636 T468 n:127.0.0.1:59636__rv x:collection1
oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 114637 T468 n:127.0.0.1:59636__rv x:collection1
oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 114642 T468 n:127.0.0.1:59636__rv x:collection1
oasc.RequestHandlers.initHandlersFromConfig Registered paths:
/admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/update,/admin/file
[junit4] 2> 114643 T468 n:127.0.0.1:59636__rv x:collection1
oasc.SolrCore.initStatsCache Using default statsCache cache:
org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 114645 T468 n:127.0.0.1:59636__rv x:collection1
oasu.UpdateHandler.<init> Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 114645 T468 n:127.0.0.1:59636__rv x:collection1
oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10
[junit4] 2> 114651 T468 n:127.0.0.1:59636__rv x:collection1
oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 114652 T468 n:127.0.0.1:59636__rv x:collection1
oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 114653 T468 n:127.0.0.1:59636__rv x:collection1
oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy:
minMergeSize=1000, mergeFactor=25, maxMergeSize=9223372036854775807,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.0]
[junit4] 2> 114653 T468 n:127.0.0.1:59636__rv x:collection1
oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2>
commit{dir=MockDirectoryWrapper(RAMDirectory@244c3e72
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1807099b),segFN=segments_1,generation=1}
[junit4] 2> 114653 T468 n:127.0.0.1:59636__rv x:collection1
oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 114654 T468 n:127.0.0.1:59636__rv x:collection1
oass.SolrIndexSearcher.<init> Opening Searcher@4116650c[collection1] main
[junit4] 2> 114654 T468 n:127.0.0.1:59636__rv x:collection1
oascc.ZkStateReader.readConfigName Load collection config
from:/collections/collection1
[junit4] 2> 114658 T468 n:127.0.0.1:59636__rv x:collection1
oascc.ZkStateReader.readConfigName path=/collections/collection1
configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 114659 T468 n:127.0.0.1:59636__rv x:collection1
oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for
the RestManager with znodeBase: /configs/conf1
[junit4] 2> 114659 T468 n:127.0.0.1:59636__rv x:collection1
oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured
ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 114660 T468 n:127.0.0.1:59636__rv x:collection1
oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 114660 T468 n:127.0.0.1:59636__rv x:collection1
oasr.ManagedResourceStorage.load Reading _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 114661 T468 n:127.0.0.1:59636__rv x:collection1
oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found
for znode /configs/conf1/_rest_managed.json
[junit4] 2> 114662 T468 n:127.0.0.1:59636__rv x:collection1
oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 114662 T468 n:127.0.0.1:59636__rv x:collection1
oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 114662 T468 n:127.0.0.1:59636__rv x:collection1
oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 114665 T469 n:127.0.0.1:59636__rv x:collection1
oasc.SolrCore.registerSearcher [collection1] Registered new searcher
Searcher@4116650c[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 114666 T468 n:127.0.0.1:59636__rv x:collection1
oasc.ZkController.getConfDirListeners watch zkdir /configs/conf1
[junit4] 2> 114667 T468 n:127.0.0.1:59636__rv x:collection1
oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 114668 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oasc.ZkController.register Register replica - core:collection1
address:http://127.0.0.1:59636/_rv collection:collection1 shard:shard1
[junit4] 2> 114669 T411 n:127.0.0.1:59636__rv oass.SolrDispatchFilter.init
user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1
[junit4] 2> 114670 T411 n:127.0.0.1:59636__rv oass.SolrDispatchFilter.init
SolrDispatchFilter.init() done
[junit4] 2> 114671 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 114676 T411 oas.SolrTestCaseJ4.setUp ###Starting
testSolrJAPICalls
[junit4] 2> 114684 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess Running the
leader process for shard shard1
[junit4] 2> 114688 T439 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/queue state SyncConnected
[junit4] 2> 114690 T440 n:127.0.0.1:59632__rv
oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1"} current state version: 4
[junit4] 2> 114697 T454 n:127.0.0.1:59636__rv
oasha.CollectionsHandler.handleCreateAction Creating Collection :
async=1001&collection.configName=conf1&name=testasynccollectioncreation&action=CREATE&numShards=1&wt=javabin&version=2
[junit4] 2> 114699 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough
replicas found to continue.
[junit4] 2> 114699 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new
leader - try and sync
[junit4] 2> ASYNC NEW_CORE C85 name=collection1
org.apache.solr.core.SolrCore@624c6ae6
url=http://127.0.0.1:59636/_rv/collection1 node=127.0.0.1:59636__rv
C85_STATE=coll:collection1 core:collection1 props:{core=collection1,
base_url=http://127.0.0.1:59636/_rv, node_name=127.0.0.1:59636__rv, state=down}
[junit4] 2> 114699 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 C85 oasc.SyncStrategy.sync Sync replicas to
http://127.0.0.1:59636/_rv/collection1/
[junit4] 2> 114700 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 C85 oasc.SyncStrategy.syncReplicas Sync Success - now sync
replicas to me
[junit4] 2> 114700 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 C85 oasc.SyncStrategy.syncToMe
http://127.0.0.1:59636/_rv/collection1/ has no replicas
[junit4] 2> 114700 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new
leader: http://127.0.0.1:59636/_rv/collection1/ shard1
[junit4] 2> 114700 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 114711 T439 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/collection-queue-work state SyncConnected
[junit4] 2> 114712 T454 n:127.0.0.1:59636__rv
oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null
path=/admin/collections
params={async=1001&collection.configName=conf1&name=testasynccollectioncreation&action=CREATE&numShards=1&wt=javabin&version=2}
status=0 QTime=20
[junit4] 2> 114716 T441 n:127.0.0.1:59632__rv
oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the
message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "operation":"create",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"testasynccollectioncreation",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"1",
[junit4] 2> "async":"1001",
[junit4] 2> "stateFormat":"2"}
[junit4] 2> 114721 T474 n:127.0.0.1:59632__rv
c:testasynccollectioncreation oasc.OverseerCollectionProcessor.processMessage
WARN OverseerCollectionProcessor.processMessage : create , {
[junit4] 2> "operation":"create",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"testasynccollectioncreation",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"1",
[junit4] 2> "async":"1001",
[junit4] 2> "stateFormat":"2"}
[junit4] 2> 114723 T439 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/queue state SyncConnected
[junit4] 2> 114727 T440 n:127.0.0.1:59632__rv
oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://127.0.0.1:59636/_rv";,
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 4
[junit4] 2> 114736 T455 n:127.0.0.1:59636__rv
oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null
path=/admin/collections
params={requestid=1001&action=REQUESTSTATUS&wt=javabin&version=2} status=0
QTime=6
[junit4] 2> 114740 T474 n:127.0.0.1:59632__rv
c:testasynccollectioncreation oasc.OverseerCollectionProcessor.createConfNode
creating collections conf node /collections/testasynccollectioncreation
[junit4] 2> 114741 T474 n:127.0.0.1:59632__rv
c:testasynccollectioncreation oascc.SolrZkClient.makePath makePath:
/collections/testasynccollectioncreation
[junit4] 2> 114751 T439 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/queue state SyncConnected
[junit4] 2> 114753 T440 n:127.0.0.1:59632__rv
oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"create",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"testasynccollectioncreation",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"1",
[junit4] 2> "async":"1001",
[junit4] 2> "stateFormat":"2"} current state version: 4
[junit4] 2> 114754 T440 n:127.0.0.1:59632__rv
oasco.ClusterStateMutator.createCollection building a new cName:
testasynccollectioncreation
[junit4] 2> 114756 T450 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> 114763 T439 n:127.0.0.1:59632__rv
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> 114763 T467 n:127.0.0.1:59636__rv
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> 114778 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oasc.ZkController.register We are
http://127.0.0.1:59636/_rv/collection1/ and leader is
http://127.0.0.1:59636/_rv/collection1/
[junit4] 2> 114779 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oasc.ZkController.register No LogReplay needed for
core=collection1 baseURL=http://127.0.0.1:59636/_rv
[junit4] 2> 114779 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oasc.ZkController.checkRecovery I am the leader, no recovery
necessary
[junit4] 2> 114779 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oasc.ZkController.publish publishing core=collection1
state=active collection=collection1
[junit4] 2> 114779 T472 n:127.0.0.1:59636__rv c:collection1 s:shard1
x:collection1 oasc.ZkController.publish numShards not found on descriptor -
reading it from system property
[junit4] 2> 114785 T439 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/queue state SyncConnected
[junit4] 2> 114789 T440 n:127.0.0.1:59632__rv
oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59636/_rv";,
[junit4] 2> "node_name":"127.0.0.1:59636__rv",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"} current state version: 5
[junit4] 2> 114790 T440 n:127.0.0.1:59632__rv
oasco.ReplicaMutator.updateState Update state numShards=1 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59636/_rv";,
[junit4] 2> "node_name":"127.0.0.1:59636__rv",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 114792 T440 n:127.0.0.1:59632__rv
oasco.ZkStateWriter.writePendingUpdates going to create_collection
/collections/testasynccollectioncreation/state.json
[junit4] 2> 114797 T467 n:127.0.0.1:59636__rv
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> 114797 T450 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> 114798 T439 n:127.0.0.1:59632__rv
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> 114852 T474 n:127.0.0.1:59632__rv
c:testasynccollectioncreation oasc.OverseerCollectionProcessor.createCollection
Creating SolrCores for new collection testasynccollectioncreation, shardNames
[shard1] , replicationFactor : 1
[junit4] 2> 114852 T474 n:127.0.0.1:59632__rv
c:testasynccollectioncreation oasc.OverseerCollectionProcessor.createCollection
Creating shard testasynccollectioncreation_shard1_replica1 as part of slice
shard1 of collection testasynccollectioncreation on 127.0.0.1:59636__rv
[junit4] 2> 114876 T456 n:127.0.0.1:59636__rv
oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null
path=/admin/cores
params={async=1001501359000883144&qt=/admin/cores&collection.configName=conf1&name=testasynccollectioncreation_shard1_replica1&action=CREATE&numShards=1&collection=testasynccollectioncreation&shard=shard1&wt=javabin&version=2}
status=0 QTime=14
[junit4] 2> 114877 T476 n:127.0.0.1:59636__rv
oasha.CoreAdminHandler.handleCreateAction core create command
async=1001501359000883144&qt=/admin/cores&collection.configName=conf1&name=testasynccollectioncreation_shard1_replica1&action=CREATE&numShards=1&collection=testasynccollectioncreation&shard=shard1&wt=javabin&version=2
[junit4] 2> 114878 T476 n:127.0.0.1:59636__rv oasc.CoreDescriptor.<init>
CORE DESCRIPTOR: {name=testasynccollectioncreation_shard1_replica1,
config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true,
instanceDir=testasynccollectioncreation_shard1_replica1,
collection=testasynccollectioncreation,
absoluteInstDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/testasynccollectioncreation_shard1_replica1/,
numShards=1, dataDir=data/, shard=shard1}
[junit4] 2> 114885 T457 n:127.0.0.1:59636__rv
oasha.CoreAdminHandler.handleRequestActionStatus Checking request status for :
1001501359000883144
[junit4] 2> 114885 T457 n:127.0.0.1:59636__rv
oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null
path=/admin/cores
params={qt=/admin/cores&requestid=1001501359000883144&action=REQUESTSTATUS&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 114899 T476 n:127.0.0.1:59636__rv
c:testasynccollectioncreation x:testasynccollectioncreation_shard1_replica1
oasc.ZkController.publish publishing
core=testasynccollectioncreation_shard1_replica1 state=down
collection=testasynccollectioncreation
[junit4] 2> 114922 T467 n:127.0.0.1:59636__rv
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> 114922 T450 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> 114932 T439 n:127.0.0.1:59632__rv
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> 114934 T477 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/queue state SyncConnected
[junit4] 2> 114942 T476 n:127.0.0.1:59636__rv
oasc.ZkController.preRegister Registering watch for external collection
testasynccollectioncreation
[junit4] 2> 114947 T476 n:127.0.0.1:59636__rv
oascc.ZkStateReader.addZkWatch addZkWatch testasynccollectioncreation
[junit4] 2> 114948 T476 n:127.0.0.1:59636__rv
oascc.ZkStateReader.addZkWatch Updating collection state at
/collections/testasynccollectioncreation/state.json from ZooKeeper...
[junit4] 2> 114954 T440 n:127.0.0.1:59632__rv
oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
[junit4] 2> "core":"testasynccollectioncreation_shard1_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59636/_rv";,
[junit4] 2> "node_name":"127.0.0.1:59636__rv",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testasynccollectioncreation",
[junit4] 2> "operation":"state"} current state version: 7
[junit4] 2> 114955 T440 n:127.0.0.1:59632__rv
oasco.ReplicaMutator.updateState Update state numShards=1 message={
[junit4] 2> "core":"testasynccollectioncreation_shard1_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:59636/_rv";,
[junit4] 2> "node_name":"127.0.0.1:59636__rv",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testasynccollectioncreation",
[junit4] 2> "operation":"state"}
[junit4] 2> 114965 T476 n:127.0.0.1:59636__rv
oascc.ZkStateReader.updateWatchedCollection Updating data for
testasynccollectioncreation to ver 0
[junit4] 2> 114965 T476 n:127.0.0.1:59636__rv
oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 114970 T439 n:127.0.0.1:59632__rv
oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path
/overseer/queue state SyncConnected
[junit4] 2> 114974 T440 n:127.0.0.1:59632__rv
oasco.ZkStateWriter.writePendingUpdates going to update_collection
/collections/testasynccollectioncreation/state.json version: 0
[junit4] 2> 114976 T467 n:127.0.0.1:59636__rv
oascc.ZkStateReader$7.process A cluster state change: WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/testasynccollectioncreation/state.json for collection
testasynccollectioncreation has occurred - updating... (live nodes size: 2)
[junit4] 2> 114978 T467 n:127.0.0.1:59636__rv
oascc.ZkStateReader.updateWatchedCollection Updating data for
testasynccollectioncreation to ver 1
[junit4] 2> 115748 T458 n:127.0.0.1:59636__rv
oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null
path=/admin/collections
params={requestid=1001&action=REQUESTSTATUS&wt=javabin&version=2} status=0
QTime=5
[junit4] 2> 115891 T459 n:127.0.0.1:59636__rv
oasha.CoreAdminHandler.handleRequestActionStatus Checking request status for :
1001501359000883144
[junit4] 2> 115892 T459 n:127.0.0.1:59636__rv
oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null
path=/admin/cores
params={qt=/admin/cores&requestid=1001501359000883144&action=REQUESTSTATUS&wt=javabin&version=2}
status=0 QTime=1
[junit4] 2> 115967 T476 n:127.0.0.1:59636__rv
oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for
testasynccollectioncreation_shard1_replica1
[junit4] 2> 115967 T476 n:127.0.0.1:59636__rv
oasc.ZkController.createCollectionZkNode Check for collection
zkNode:testasynccollectioncreation
[junit4] 2> 115969 T476 n:127.0.0.1:59636__rv
oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 115969 T476 n:127.0.0.1:59636__rv
oascc.ZkStateReader.readConfigName Load collection config
from:/collections/testasynccollectioncreation
[junit4] 2> 115981 T476 n:127.0.0.1:59636__rv
oascc.ZkStateReader.readConfigName
path=/collections/testasynccollectioncreation configName=conf1 specified config
exists in ZooKeeper
[junit4] 2> 115982 T476 n:127.0.0.1:59636__rv
oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory:
'/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/testasynccollectioncreation_shard1_replica1/'
[junit4] 2> 116031 T476 n:127.0.0.1:59636__rv oasc.Config.<init> loaded
config solrconfig.xml with version 0
[junit4] 2> 116043 T476 n:127.0.0.1:59636__rv
oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
[junit4] 2> 116046 T476 n:127.0.0.1:59636__rv oasc.SolrConfig.<init> Using
Lucene MatchVersion: 6.0.0
[junit4] 2> 116053 T476 n:127.0.0.1:59636__rv oasc.SolrConfig.<init>
Loaded SolrConfig: solrconfig.xml
[junit4] 2> 116055 T476 n:127.0.0.1:59636__rv oass.IndexSchema.readSchema
Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 116061 T476 n:127.0.0.1:59636__rv oass.IndexSchema.readSchema
[testasynccollectioncreation_shard1_replica1] Schema name=test
[junit4] 2> 116147 T476 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider.init Initialized with
rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 116155 T476 n:127.0.0.1:59636__rv oass.IndexSchema.readSchema
default search field in schema is text
[junit4] 2> 116157 T476 n:127.0.0.1:59636__rv oass.IndexSchema.readSchema
unique key field: id
[junit4] 2> 116203 T476 n:127.0.0.1:59636__rv
oass.FileExchangeRateProvider.reload Reloading exchange rates from file
currency.xml
[junit4] 2> 116210 T476 n:127.0.0.1:59636__rv
oass.FileExchangeRateProvider.reload Reloading exchange rates from file
currency.xml
[junit4] 2> 116214 T476 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from
open-exchange-rates.json
[junit4] 2> 116217 T476 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 116217 T476 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 116217 T476 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from
open-exchange-rates.json
[junit4] 2> 116221 T476 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key
IMPORTANT NOTE
[junit4] 2> 116221 T476 n:127.0.0.1:59636__rv
oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key,
got STRING
[junit4] 2> 116221 T476 n:127.0.0.1:59636__rv oasc.CoreContainer.create
Creating SolrCore 'testasynccollectioncreation_shard1_replica1' using
configuration from collection testasynccollectioncreation
[junit4] 2> 116221 T476 n:127.0.0.1:59636__rv
x:testasynccollectioncreation_shard1_replica1
oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 116221 T476 n:127.0.0.1:59636__rv
x:testasynccollectioncreation_shard1_replica1 oasc.SolrCore.<init>
[[testasynccollectioncreation_shard1_replica1] ] Opening new SolrCore at
[/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/testasynccollectioncreation_shard1_replica1/],
dataDir=[null]
[junit4] 2> 116227 T4
[...truncated too long message...]
-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/testasynccollectioncreation_shard1_0_replica1/data/index
[junit4] 2> 246697 T411 oasc.SolrCore.close
[testasynccollectioncreation_shard1_1_replica1] CLOSING SolrCore
org.apache.solr.core.SolrCore@74783a4f
[junit4] 2> 246697 T411 oasc.ZkController.unregisterConfListener removed
listener for config directory [/configs/conf1]
[junit4] 2> 246697 T411 oasc.ZkController.unregisterConfListener No more
listeners for config directory [/configs/conf1]
[junit4] 2> 246697 T411 oasu.DirectUpdateHandler2.close closing
DirectUpdateHandler2{commits=1,autocommits=0,soft
autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 246698 T411 oasu.SolrCoreState.decrefSolrCoreState Closing
SolrCoreState
[junit4] 2> 246698 T411 oasu.DefaultSolrCoreState.closeIndexWriter
SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 246698 T411 oasu.DefaultSolrCoreState.closeIndexWriter closing
IndexWriter with IndexWriterCloser
[junit4] 2> 246701 T411 oasc.SolrCore.closeSearcher
[testasynccollectioncreation_shard1_1_replica1] Closing main searcher on
request.
[junit4] 2> 246712 T411 oasc.CachingDirectoryFactory.close Closing
MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 246712 T411 oasc.CachingDirectoryFactory.closeCacheValue
looking to close
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/testasynccollectioncreation_shard1_1_replica1/data/index
[CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/testasynccollectioncreation_shard1_1_replica1/data/index;done=false>>]
[junit4] 2> 246713 T411 oasc.CachingDirectoryFactory.close Closing
directory:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/testasynccollectioncreation_shard1_1_replica1/data/index
[junit4] 2> 246713 T411 oasc.CachingDirectoryFactory.closeCacheValue
looking to close
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/testasynccollectioncreation_shard1_1_replica1/data
[CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/testasynccollectioncreation_shard1_1_replica1/data;done=false>>]
[junit4] 2> 246713 T411 oasc.CachingDirectoryFactory.close Closing
directory:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001/shard-1-001/cores/testasynccollectioncreation_shard1_1_replica1/data
[junit4] 2> 246713 T411 oasc.Overseer.close Overseer
(id=93748106075373574-127.0.0.1:59636__rv-n_0000000001) closing
[junit4] 2> 246714 T517 n:127.0.0.1:59636__rv
oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting :
127.0.0.1:59636__rv
[junit4] 2> 246720 T466 n:127.0.0.1:59636__rv
oaz.ClientCnxn$EventThread.processEvent ERROR Error while calling watcher
java.util.concurrent.RejectedExecutionException: Task
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1@128a6629
rejected from
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@4bedb35d[Shutting
down, pool size = 1, active threads = 0, queued tasks = 0, completed tasks =
38]
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2047)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.execute(ExecutorUtil.java:135)
[junit4] 2> at
java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:261)
[junit4] 2> at
org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at
org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 246725 T411 oejs.AbstractConnector.doStop Stopped
ServerConnector@294784ca{HTTP/1.1}{127.0.0.1:0}
[junit4] 2> 246725 T411 oejsh.ContextHandler.doStop Stopped
o.e.j.s.ServletContextHandler@3b4b9605{/_rv,null,UNAVAILABLE}
[junit4] 2> 246728 T411 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:59629 59629
[junit4] 2> 246749 T412 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:59629 59629
[junit4] 2> 248008 T412 oasc.ZkTestServer$ZKServerMain.runFromConfig WARN
Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2> 2 /solr/configs/conf1
[junit4] 2> 2
/solr/collections/testasynccollectioncreation/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 2 /solr/overseer/queue
[junit4] 2> 2 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=CollectionsAPIAsyncDistributedZkTest
-Dtests.method=testSolrJAPICalls -Dtests.seed=6C4EE8531FF12691
-Dtests.slow=true -Dtests.locale=be -Dtests.timezone=Australia/Eucla
-Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 139s J1 |
CollectionsAPIAsyncDistributedZkTest.testSolrJAPICalls <<<
[junit4] > Throwable #1: org.junit.ComparisonFailure: Shard split did not
complete. Last recorded state: running expected:<[completed]> but
was:<[running]>
[junit4] > at
__randomizedtesting.SeedInfo.seed([6C4EE8531FF12691:342A6432199B8E45]:0)
[junit4] > at
org.apache.solr.cloud.CollectionsAPIAsyncDistributedZkTest.testSolrJAPICalls(CollectionsAPIAsyncDistributedZkTest.java:101)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:960)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 248187 T411 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest
6C4EE8531FF12691-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene50): {},
docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {},
locale=be, timezone=Australia/Eucla
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_45
(64-bit)/cpus=3,threads=1,free=99929200,total=197132288
[junit4] 2> NOTE: All tests run in this JVM:
[TermVectorComponentDistributedTest, StatsComponentTest,
SpellingQueryConverterTest, TestRTGBase, TestBadConfig, ResponseHeaderTest,
RecoveryAfterSoftCommitTest, TestRecovery, CollectionsAPIAsyncDistributedZkTest]
[junit4] Completed [31/485] on J1 in 138.91s, 1 test, 1 failure <<< FAILURES!
[...truncated 1418 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:526: The following
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:474: The following
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:61: The following
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:39: The
following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:229: The
following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:512:
The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1415:
The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:973:
There were test failures: 485 suites, 1948 tests, 1 failure, 62 ignored (24
assumptions)
Total time: 60 minutes 40 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
