You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/03/21 03:37:02 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b79) - Build #
4801 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4801/
Java: 32bit/jdk1.8.0-ea-b79 -client -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
Server at http://127.0.0.1:49791/qkk/onenodecollectioncore returned non ok status:404, message:Can not find: /qkk/onenodecollectioncore/update
Stack Trace:
org.apache.solr.common.SolrException: Server at http://127.0.0.1:49791/qkk/onenodecollectioncore returned non ok status:404, message:Can not find: /qkk/onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([7CDEF2EA1AD216F6:FD387CF26D8D76CA]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:375)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:487)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:722)
Build Log:
[...truncated 9103 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4] 2> 0 T935 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /qkk/
[junit4:junit4] 2> 6 T935 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626
[junit4:junit4] 2> 7 T935 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 8 T936 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 10 T936 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 10 T936 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 11 T936 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 11 T936 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 13 T936 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 108 T935 oasc.ZkTestServer.run start zk server on port:44044
[junit4:junit4] 2> 109 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@d50d12
[junit4:junit4] 2> 111 T941 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 110 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 111 T941 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 112 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53264
[junit4:junit4] 2> 112 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53264
[junit4:junit4] 2> 113 T939 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 116 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac275380000 with negotiated timeout 10000 for client /127.0.0.1:53264
[junit4:junit4] 2> 116 T941 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac275380000, negotiated timeout = 10000
[junit4:junit4] 2> 117 T942 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d50d12 name:ZooKeeperConnection Watcher:127.0.0.1:44044 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 117 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 118 T935 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 122 T940 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8ac275380000
[junit4:junit4] 2> 123 T942 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 123 T937 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:53264 which had sessionid 0x13d8ac275380000
[junit4:junit4] 2> 123 T935 oaz.ZooKeeper.close Session: 0x13d8ac275380000 closed
[junit4:junit4] 2> 124 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@12e238
[junit4:junit4] 2> 125 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 126 T943 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 127 T943 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 127 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53266
[junit4:junit4] 2> 127 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53266
[junit4:junit4] 2> 128 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac275380001 with negotiated timeout 10000 for client /127.0.0.1:53266
[junit4:junit4] 2> 128 T943 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac275380001, negotiated timeout = 10000
[junit4:junit4] 2> 129 T944 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12e238 name:ZooKeeperConnection Watcher:127.0.0.1:44044/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 130 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 130 T935 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 134 T935 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 137 T935 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 140 T935 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 143 T935 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 145 T935 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 156 T935 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 158 T935 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 168 T935 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 169 T935 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 172 T935 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 173 T935 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 177 T935 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 179 T935 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 183 T935 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 184 T935 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 187 T935 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 188 T935 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 191 T935 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 192 T935 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 195 T935 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 196 T935 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 199 T940 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8ac275380001
[junit4:junit4] 2> 200 T944 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 200 T937 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:53266 which had sessionid 0x13d8ac275380001
[junit4:junit4] 2> 200 T935 oaz.ZooKeeper.close Session: 0x13d8ac275380001 closed
[junit4:junit4] 2> 280 T935 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 300 T935 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46503
[junit4:junit4] 2> 301 T935 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 301 T935 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 302 T935 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1363832632820
[junit4:junit4] 2> 302 T935 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1363832632820/solr.xml
[junit4:junit4] 2> 303 T935 oasc.CoreContainer.<init> New CoreContainer 5257805
[junit4:junit4] 2> 303 T935 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1363832632820/'
[junit4:junit4] 2> 304 T935 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1363832632820/'
[junit4:junit4] 2> 331 T935 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 331 T935 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 332 T935 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 332 T935 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 332 T935 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 333 T935 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 333 T935 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 333 T935 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 334 T935 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 334 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 345 T935 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 360 T935 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:44044/solr
[junit4:junit4] 2> 361 T935 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 361 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@15aa9f9
[junit4:junit4] 2> 362 T954 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 362 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 363 T954 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 363 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53269
[junit4:junit4] 2> 363 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53269
[junit4:junit4] 2> 365 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac275380002 with negotiated timeout 20000 for client /127.0.0.1:53269
[junit4:junit4] 2> 365 T954 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac275380002, negotiated timeout = 20000
[junit4:junit4] 2> 365 T955 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15aa9f9 name:ZooKeeperConnection Watcher:127.0.0.1:44044 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 365 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 366 T940 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8ac275380002
[junit4:junit4] 2> 367 T955 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 367 T935 oaz.ZooKeeper.close Session: 0x13d8ac275380002 closed
[junit4:junit4] 2> 367 T937 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:53269 which had sessionid 0x13d8ac275380002
[junit4:junit4] 2> 367 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 370 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1bc5669
[junit4:junit4] 2> 371 T956 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 371 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 372 T956 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 372 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53270
[junit4:junit4] 2> 372 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53270
[junit4:junit4] 2> 373 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac275380003 with negotiated timeout 20000 for client /127.0.0.1:53270
[junit4:junit4] 2> 373 T956 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac275380003, negotiated timeout = 20000
[junit4:junit4] 2> 374 T957 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bc5669 name:ZooKeeperConnection Watcher:127.0.0.1:44044/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 374 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 376 T935 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 378 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380003 type:create cxid:0x7 zxid:0x1b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 385 T935 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 387 T935 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 389 T935 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46503_qkk
[junit4:junit4] 2> 390 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380003 type:delete cxid:0x12 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:46503_qkk Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:46503_qkk
[junit4:junit4] 2> 391 T935 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46503_qkk
[junit4:junit4] 2> 394 T935 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 399 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380003 type:delete cxid:0x20 zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 400 T935 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 402 T935 oasc.Overseer.start Overseer (id=89380135412170755-127.0.0.1:46503_qkk-n_0000000000) starting
[junit4:junit4] 2> 403 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380003 type:create cxid:0x25 zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 404 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380003 type:create cxid:0x26 zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 405 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380003 type:create cxid:0x28 zxid:0x27 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 406 T935 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 409 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380003 type:create cxid:0x2e zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 411 T959 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 413 T935 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 416 T935 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 418 T935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 421 T958 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 426 T960 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1363832632820/collection1
[junit4:junit4] 2> 427 T960 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 428 T960 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 428 T960 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 430 T960 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1363832632820/collection1/'
[junit4:junit4] 2> 431 T960 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1363832632820/collection1/lib/README' to classloader
[junit4:junit4] 2> 431 T960 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1363832632820/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 492 T960 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 543 T960 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 544 T960 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 548 T960 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 1229 T960 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1238 T960 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1240 T960 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1256 T960 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1260 T960 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1265 T960 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1266 T960 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1267 T960 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1267 T960 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1269 T960 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1269 T960 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1269 T960 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1270 T960 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1363832632820/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/control/data/
[junit4:junit4] 2> 1270 T960 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@89c25c
[junit4:junit4] 2> 1271 T960 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1272 T960 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/control/data forceNew: false
[junit4:junit4] 2> 1272 T960 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/control/data/index/
[junit4:junit4] 2> 1272 T960 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1273 T960 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/control/data/index forceNew: false
[junit4:junit4] 2> 1275 T960 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@40bda6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@44932c),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 1275 T960 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 1277 T960 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1277 T960 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1278 T960 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1279 T960 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1279 T960 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1280 T960 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1280 T960 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1280 T960 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1281 T960 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1285 T960 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1289 T960 oass.SolrIndexSearcher.<init> Opening Searcher@f6462 main
[junit4:junit4] 2> 1289 T960 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/control/data/tlog
[junit4:junit4] 2> 1293 T960 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1293 T960 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1298 T961 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f6462 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1299 T960 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1299 T960 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1926 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1927 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:46503/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:46503_qkk",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 1928 T958 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 1928 T958 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 1933 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 2301 T960 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2302 T960 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:46503/qkk collection:control_collection shard:shard1
[junit4:junit4] 2> 2303 T960 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2313 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380003 type:delete cxid:0x82 zxid:0x35 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4] 2> 2314 T960 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2315 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380003 type:create cxid:0x83 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2318 T960 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2318 T960 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2319 T960 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:46503/qkk/collection1/
[junit4:junit4] 2> 2319 T960 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2319 T960 oasc.SyncStrategy.syncToMe http://127.0.0.1:46503/qkk/collection1/ has no replicas
[junit4:junit4] 2> 2320 T960 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:46503/qkk/collection1/
[junit4:junit4] 2> 2320 T960 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2325 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380003 type:create cxid:0x8e zxid:0x3a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3439 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3449 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 3481 T960 oasc.ZkController.register We are http://127.0.0.1:46503/qkk/collection1/ and leader is http://127.0.0.1:46503/qkk/collection1/
[junit4:junit4] 2> 3481 T960 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46503/qkk
[junit4:junit4] 2> 3482 T960 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 3482 T960 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 3482 T960 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 3484 T960 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3486 T935 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 3486 T935 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 3487 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 3493 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 3495 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@5b589f
[junit4:junit4] 2> 3496 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3496 T963 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3497 T963 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 3497 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53271
[junit4:junit4] 2> 3498 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53271
[junit4:junit4] 2> 3499 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac275380004 with negotiated timeout 10000 for client /127.0.0.1:53271
[junit4:junit4] 2> 3499 T963 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac275380004, negotiated timeout = 10000
[junit4:junit4] 2> 3500 T964 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b589f name:ZooKeeperConnection Watcher:127.0.0.1:44044/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3500 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3503 T935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3511 T935 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 3589 T935 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 3591 T935 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:37815
[junit4:junit4] 2> 3592 T935 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 3592 T935 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 3592 T935 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131
[junit4:junit4] 2> 3593 T935 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131/solr.xml
[junit4:junit4] 2> 3593 T935 oasc.CoreContainer.<init> New CoreContainer 28875518
[junit4:junit4] 2> 3593 T935 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131/'
[junit4:junit4] 2> 3594 T935 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131/'
[junit4:junit4] 2> 3615 T935 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 3615 T935 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 3615 T935 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 3616 T935 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 3616 T935 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 3616 T935 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 3617 T935 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 3617 T935 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 3617 T935 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 3618 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 3627 T935 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 3644 T935 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:44044/solr
[junit4:junit4] 2> 3645 T935 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 3645 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@49cb8d
[junit4:junit4] 2> 3646 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3646 T974 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3647 T974 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 3647 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53272
[junit4:junit4] 2> 3647 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53272
[junit4:junit4] 2> 3648 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac275380005 with negotiated timeout 20000 for client /127.0.0.1:53272
[junit4:junit4] 2> 3648 T974 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac275380005, negotiated timeout = 20000
[junit4:junit4] 2> 3649 T975 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49cb8d name:ZooKeeperConnection Watcher:127.0.0.1:44044 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3649 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3650 T940 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8ac275380005
[junit4:junit4] 2> 3651 T975 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 3651 T937 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:53272 which had sessionid 0x13d8ac275380005
[junit4:junit4] 2> 3651 T935 oaz.ZooKeeper.close Session: 0x13d8ac275380005 closed
[junit4:junit4] 2> 3651 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 3655 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@a7dea4
[junit4:junit4] 2> 3657 T976 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3657 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3657 T976 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 3658 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53273
[junit4:junit4] 2> 3658 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53273
[junit4:junit4] 2> 3659 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac275380006 with negotiated timeout 20000 for client /127.0.0.1:53273
[junit4:junit4] 2> 3659 T976 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac275380006, negotiated timeout = 20000
[junit4:junit4] 2> 3660 T977 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a7dea4 name:ZooKeeperConnection Watcher:127.0.0.1:44044/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3660 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3662 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:create cxid:0x1 zxid:0x48 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3664 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:create cxid:0x3 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3667 T935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 4671 T935 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37815_qkk
[junit4:junit4] 2> 4672 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:delete cxid:0xd zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:37815_qkk Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:37815_qkk
[junit4:junit4] 2> 4673 T935 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37815_qkk
[junit4:junit4] 2> 4678 T957 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4678 T964 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4678 T977 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4678 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 4688 T978 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131/collection1
[junit4:junit4] 2> 4688 T978 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 4689 T978 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 4689 T978 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 4691 T978 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131/collection1/'
[junit4:junit4] 2> 4692 T978 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131/collection1/lib/README' to classloader
[junit4:junit4] 2> 4697 T978 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 4758 T978 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 4832 T978 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 4834 T978 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 4838 T978 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 4955 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 4956 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:46503/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "node_name":"127.0.0.1:46503_qkk",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 4960 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 4960 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 4961 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 5743 T978 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 5749 T978 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 5755 T978 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 5767 T978 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5773 T978 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5778 T978 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5779 T978 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5780 T978 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5780 T978 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5782 T978 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5782 T978 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5783 T978 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 5783 T978 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty1/
[junit4:junit4] 2> 5783 T978 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@89c25c
[junit4:junit4] 2> 5784 T978 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 5785 T978 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty1 forceNew: false
[junit4:junit4] 2> 5785 T978 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty1/index/
[junit4:junit4] 2> 5785 T978 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 5786 T978 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty1/index forceNew: false
[junit4:junit4] 2> 5794 T978 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f991bd lockFactory=org.apache.lucene.store.NativeFSLockFactory@1e58434),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 5795 T978 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 5797 T978 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 5798 T978 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 5799 T978 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 5800 T978 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 5801 T978 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 5801 T978 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 5801 T978 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 5802 T978 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 5803 T978 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 5808 T978 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 5813 T978 oass.SolrIndexSearcher.<init> Opening Searcher@1e16d72 main
[junit4:junit4] 2> 5813 T978 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty1/tlog
[junit4:junit4] 2> 5814 T978 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 5815 T978 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 5822 T979 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e16d72 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 5824 T978 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 5825 T978 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6470 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6471 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37815/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:37815_qkk",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 6472 T958 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 6472 T958 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 6477 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 6477 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 6477 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 6826 T978 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 6827 T978 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37815/qkk collection:collection1 shard:shard1
[junit4:junit4] 2> 6828 T978 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 6837 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:delete cxid:0x4a zxid:0x5a txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4] 2> 6838 T978 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 6839 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:create cxid:0x4b zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 6842 T978 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 6843 T978 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 6843 T978 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37815/qkk/collection1/
[junit4:junit4] 2> 6844 T978 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 6844 T978 oasc.SyncStrategy.syncToMe http://127.0.0.1:37815/qkk/collection1/ has no replicas
[junit4:junit4] 2> 6845 T978 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37815/qkk/collection1/
[junit4:junit4] 2> 6845 T978 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 6852 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:create cxid:0x56 zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7990 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8000 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 8000 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 8000 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 8007 T978 oasc.ZkController.register We are http://127.0.0.1:37815/qkk/collection1/ and leader is http://127.0.0.1:37815/qkk/collection1/
[junit4:junit4] 2> 8008 T978 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37815/qkk
[junit4:junit4] 2> 8008 T978 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 8009 T978 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 8009 T978 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8011 T978 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8013 T935 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 8014 T935 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 8015 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8102 T935 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8105 T935 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49791
[junit4:junit4] 2> 8106 T935 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8107 T935 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8107 T935 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1363832640641
[junit4:junit4] 2> 8108 T935 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1363832640641/solr.xml
[junit4:junit4] 2> 8109 T935 oasc.CoreContainer.<init> New CoreContainer 22964508
[junit4:junit4] 2> 8109 T935 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1363832640641/'
[junit4:junit4] 2> 8110 T935 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1363832640641/'
[junit4:junit4] 2> 8135 T935 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 8136 T935 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8136 T935 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8136 T935 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8137 T935 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8137 T935 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8137 T935 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8137 T935 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8138 T935 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8138 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8149 T935 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8164 T935 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:44044/solr
[junit4:junit4] 2> 8165 T935 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8165 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@190780a
[junit4:junit4] 2> 8166 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8166 T990 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8167 T990 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 8167 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53274
[junit4:junit4] 2> 8168 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53274
[junit4:junit4] 2> 8169 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac275380007 with negotiated timeout 20000 for client /127.0.0.1:53274
[junit4:junit4] 2> 8169 T990 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac275380007, negotiated timeout = 20000
[junit4:junit4] 2> 8169 T991 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@190780a name:ZooKeeperConnection Watcher:127.0.0.1:44044 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8170 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8171 T940 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8ac275380007
[junit4:junit4] 2> 8172 T991 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8172 T937 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:53274 which had sessionid 0x13d8ac275380007
[junit4:junit4] 2> 8172 T935 oaz.ZooKeeper.close Session: 0x13d8ac275380007 closed
[junit4:junit4] 2> 8172 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 8175 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@17d6049
[junit4:junit4] 2> 8176 T992 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8176 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8177 T992 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 8177 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53275
[junit4:junit4] 2> 8181 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53275
[junit4:junit4] 2> 8182 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac275380008 with negotiated timeout 20000 for client /127.0.0.1:53275
[junit4:junit4] 2> 8182 T992 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac275380008, negotiated timeout = 20000
[junit4:junit4] 2> 8182 T993 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17d6049 name:ZooKeeperConnection Watcher:127.0.0.1:44044/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8183 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8184 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380008 type:create cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8185 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380008 type:create cxid:0x3 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8186 T935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9189 T935 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49791_qkk
[junit4:junit4] 2> 9190 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380008 type:delete cxid:0xd zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49791_qkk Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49791_qkk
[junit4:junit4] 2> 9191 T935 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49791_qkk
[junit4:junit4] 2> 9195 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9195 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9195 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9196 T993 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9198 T964 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9199 T977 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9199 T957 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9205 T994 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1363832640641/collection1
[junit4:junit4] 2> 9206 T994 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9207 T994 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9207 T994 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9209 T994 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1363832640641/collection1/'
[junit4:junit4] 2> 9210 T994 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1363832640641/collection1/lib/README' to classloader
[junit4:junit4] 2> 9211 T994 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1363832640641/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9268 T994 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 9332 T994 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 9333 T994 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 9337 T994 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 9508 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9509 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37815/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "node_name":"127.0.0.1:37815_qkk",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 9514 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 9515 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 9515 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 9514 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 10192 T994 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 10200 T994 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 10204 T994 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 10223 T994 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10226 T994 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10229 T994 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10231 T994 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10231 T994 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10231 T994 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10232 T994 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10232 T994 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10233 T994 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 10233 T994 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1363832640641/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty2/
[junit4:junit4] 2> 10233 T994 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@89c25c
[junit4:junit4] 2> 10234 T994 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 10235 T994 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty2 forceNew: false
[junit4:junit4] 2> 10235 T994 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty2/index/
[junit4:junit4] 2> 10235 T994 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 10236 T994 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty2/index forceNew: false
[junit4:junit4] 2> 10237 T994 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@149c5b3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6c0c2),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 10238 T994 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 10240 T994 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 10240 T994 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 10241 T994 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 10242 T994 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 10243 T994 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 10243 T994 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 10243 T994 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 10244 T994 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 10245 T994 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 10249 T994 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 10254 T994 oass.SolrIndexSearcher.<init> Opening Searcher@4de8d2 main
[junit4:junit4] 2> 10255 T994 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty2/tlog
[junit4:junit4] 2> 10255 T994 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 10255 T994 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 10262 T995 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4de8d2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 10265 T994 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 10265 T994 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11020 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11021 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49791/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:49791_qkk",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 11022 T958 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 11022 T958 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 11027 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 11027 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 11027 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 11028 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 11267 T994 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 11267 T994 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49791/qkk collection:collection1 shard:shard2
[junit4:junit4] 2> 11269 T994 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 11276 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380008 type:delete cxid:0x49 zxid:0x7d txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4] 2> 11277 T994 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 11278 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380008 type:create cxid:0x4a zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 11281 T994 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 11281 T994 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 11281 T994 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49791/qkk/collection1/
[junit4:junit4] 2> 11282 T994 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 11282 T994 oasc.SyncStrategy.syncToMe http://127.0.0.1:49791/qkk/collection1/ has no replicas
[junit4:junit4] 2> 11282 T994 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49791/qkk/collection1/
[junit4:junit4] 2> 11283 T994 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 11288 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380008 type:create cxid:0x54 zxid:0x81 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12532 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12541 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 12541 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 12541 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 12541 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 12597 T994 oasc.ZkController.register We are http://127.0.0.1:49791/qkk/collection1/ and leader is http://127.0.0.1:49791/qkk/collection1/
[junit4:junit4] 2> 12597 T994 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49791/qkk
[junit4:junit4] 2> 12598 T994 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 12598 T994 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 12598 T994 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 12601 T994 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12603 T935 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 12604 T935 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 12604 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 12695 T935 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 12697 T935 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36333
[junit4:junit4] 2> 12698 T935 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 12698 T935 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 12699 T935 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1363832645231
[junit4:junit4] 2> 12699 T935 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1363832645231/solr.xml
[junit4:junit4] 2> 12699 T935 oasc.CoreContainer.<init> New CoreContainer 8993403
[junit4:junit4] 2> 12700 T935 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1363832645231/'
[junit4:junit4] 2> 12700 T935 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1363832645231/'
[junit4:junit4] 2> 12725 T935 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 12726 T935 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 12726 T935 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 12726 T935 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 12727 T935 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 12727 T935 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 12727 T935 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 12728 T935 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 12728 T935 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 12728 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 12735 T935 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 12763 T935 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:44044/solr
[junit4:junit4] 2> 12764 T935 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 12765 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c8ce0e
[junit4:junit4] 2> 12767 T1006 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 12766 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 12768 T1006 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 12768 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53284
[junit4:junit4] 2> 12769 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53284
[junit4:junit4] 2> 12770 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac275380009 with negotiated timeout 20000 for client /127.0.0.1:53284
[junit4:junit4] 2> 12770 T1006 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac275380009, negotiated timeout = 20000
[junit4:junit4] 2> 12770 T1007 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c8ce0e name:ZooKeeperConnection Watcher:127.0.0.1:44044 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 12771 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 12773 T940 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8ac275380009
[junit4:junit4] 2> 12774 T1007 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 12774 T937 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:53284 which had sessionid 0x13d8ac275380009
[junit4:junit4] 2> 12774 T935 oaz.ZooKeeper.close Session: 0x13d8ac275380009 closed
[junit4:junit4] 2> 12775 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 12781 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@12a66a
[junit4:junit4] 2> 12782 T1008 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 12782 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 12783 T1008 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 12783 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53285
[junit4:junit4] 2> 12784 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53285
[junit4:junit4] 2> 12785 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac27538000a with negotiated timeout 20000 for client /127.0.0.1:53285
[junit4:junit4] 2> 12785 T1008 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac27538000a, negotiated timeout = 20000
[junit4:junit4] 2> 12786 T1009 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12a66a name:ZooKeeperConnection Watcher:127.0.0.1:44044/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 12786 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 12788 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac27538000a type:create cxid:0x1 zxid:0x8e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12789 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac27538000a type:create cxid:0x3 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12792 T935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 13796 T935 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36333_qkk
[junit4:junit4] 2> 13797 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac27538000a type:delete cxid:0xd zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:36333_qkk Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:36333_qkk
[junit4:junit4] 2> 13798 T935 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36333_qkk
[junit4:junit4] 2> 13802 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13802 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13803 T957 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13803 T964 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13803 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 13804 T1009 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13804 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 13805 T977 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13806 T993 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13819 T1010 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1363832645231/collection1
[junit4:junit4] 2> 13819 T1010 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 13820 T1010 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 13820 T1010 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 13822 T1010 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1363832645231/collection1/'
[junit4:junit4] 2> 13823 T1010 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1363832645231/collection1/lib/README' to classloader
[junit4:junit4] 2> 13824 T1010 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1363832645231/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 13877 T1010 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 13954 T1010 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 13955 T1010 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 13962 T1010 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 14053 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14054 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49791/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "node_name":"127.0.0.1:49791_qkk",
[junit4:junit4] 2> "shard":"shard2"}
[junit4:junit4] 2> 14058 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 14058 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 14058 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 14058 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 14058 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 14690 T1010 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 14705 T1010 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 14709 T1010 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 14721 T1010 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14729 T1010 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14733 T1010 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14734 T1010 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 14734 T1010 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 14735 T1010 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14736 T1010 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 14737 T1010 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 14737 T1010 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 14737 T1010 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1363832645231/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty3/
[junit4:junit4] 2> 14738 T1010 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@89c25c
[junit4:junit4] 2> 14738 T1010 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 14739 T1010 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty3 forceNew: false
[junit4:junit4] 2> 14739 T1010 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty3/index/
[junit4:junit4] 2> 14739 T1010 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 14740 T1010 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty3/index forceNew: false
[junit4:junit4] 2> 14742 T1010 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1304cd5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1afa091),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 14742 T1010 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 14744 T1010 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 14745 T1010 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 14745 T1010 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 14746 T1010 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 14747 T1010 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 14747 T1010 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 14748 T1010 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 14748 T1010 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 14749 T1010 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 14753 T1010 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 14757 T1010 oass.SolrIndexSearcher.<init> Opening Searcher@6a6d50 main
[junit4:junit4] 2> 14758 T1010 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty3/tlog
[junit4:junit4] 2> 14758 T1010 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 14759 T1010 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 14769 T1011 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6a6d50 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 14772 T1010 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 14772 T1010 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 15563 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15565 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36333/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:36333_qkk",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 15565 T958 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 15565 T958 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 15571 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 15571 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 15571 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 15571 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 15571 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 15773 T1010 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 15774 T1010 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36333/qkk collection:collection1 shard:shard1
[junit4:junit4] 2> 15778 T1010 oasc.ZkController.register We are http://127.0.0.1:36333/qkk/collection1/ and leader is http://127.0.0.1:37815/qkk/collection1/
[junit4:junit4] 2> 15778 T1010 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36333/qkk
[junit4:junit4] 2> 15778 T1010 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 15779 T1010 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C56 name=collection1 org.apache.solr.core.SolrCore@1774858 url=http://127.0.0.1:36333/qkk/collection1 node=127.0.0.1:36333_qkk C56_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:36333/qkk, collection=collection1, core=collection1, state=down, node_name=127.0.0.1:36333_qkk}
[junit4:junit4] 2> 15780 T1012 C56 P36333 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 15781 T1012 C56 P36333 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 15781 T1010 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15781 T1012 C56 P36333 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 15781 T1012 C56 P36333 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 15782 T935 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 15783 T935 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 15784 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 15786 T1012 C56 P36333 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 15889 T935 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 15891 T935 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44576
[junit4:junit4] 2> 15892 T935 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 15892 T935 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 15893 T935 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1363832648410
[junit4:junit4] 2> 15893 T935 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1363832648410/solr.xml
[junit4:junit4] 2> 15893 T935 oasc.CoreContainer.<init> New CoreContainer 17726959
[junit4:junit4] 2> 15894 T935 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1363832648410/'
[junit4:junit4] 2> 15894 T935 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1363832648410/'
[junit4:junit4] 2> 15920 T935 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 15921 T935 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 15921 T935 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 15922 T935 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 15923 T935 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 15923 T935 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 15924 T935 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 15924 T935 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 15925 T935 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 15925 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 15936 T935 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 15955 T935 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:44044/solr
[junit4:junit4] 2> 15956 T935 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 15956 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@983615
[junit4:junit4] 2> 15957 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 15957 T1023 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 15959 T1023 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 15959 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53293
[junit4:junit4] 2> 15960 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53293
[junit4:junit4] 2> 15960 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac27538000b with negotiated timeout 20000 for client /127.0.0.1:53293
[junit4:junit4] 2> 15960 T1023 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac27538000b, negotiated timeout = 20000
[junit4:junit4] 2> 15961 T1024 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@983615 name:ZooKeeperConnection Watcher:127.0.0.1:44044 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 15961 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 15962 T940 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8ac27538000b
[junit4:junit4] 2> 15963 T1024 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 15963 T937 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:53293 which had sessionid 0x13d8ac27538000b
[junit4:junit4] 2> 15963 T935 oaz.ZooKeeper.close Session: 0x13d8ac27538000b closed
[junit4:junit4] 2> 15964 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 15969 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@c99e98
[junit4:junit4] 2> 15970 T1025 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 15970 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 15971 T1025 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 15971 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53294
[junit4:junit4] 2> 15972 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53294
[junit4:junit4] 2> 15973 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac27538000c with negotiated timeout 20000 for client /127.0.0.1:53294
[junit4:junit4] 2> 15973 T1025 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac27538000c, negotiated timeout = 20000
[junit4:junit4] 2> 15974 T1026 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c99e98 name:ZooKeeperConnection Watcher:127.0.0.1:44044/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 15974 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 15976 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac27538000c type:create cxid:0x1 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 15977 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac27538000c type:create cxid:0x3 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 15980 T935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 16984 T935 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44576_qkk
[junit4:junit4] 2> 16985 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac27538000c type:delete cxid:0xd zxid:0xa3 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:44576_qkk Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:44576_qkk
[junit4:junit4] 2> 16986 T935 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44576_qkk
[junit4:junit4] 2> 16989 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 16990 T964 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 16990 T993 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 16991 T1026 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 16990 T957 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 16991 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 16990 T1009 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 16990 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 16992 T977 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 16991 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 16992 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17000 T1027 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1363832648410/collection1
[junit4:junit4] 2> 17000 T1027 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 17001 T1027 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 17001 T1027 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 17003 T1027 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1363832648410/collection1/'
[junit4:junit4] 2> 17004 T1027 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1363832648410/collection1/lib/README' to classloader
[junit4:junit4] 2> 17004 T1027 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1363832648410/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 17076 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17078 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36333/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "node_name":"127.0.0.1:36333_qkk",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 17078 T1027 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 17088 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17088 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17089 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17089 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17088 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17088 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17168 T1027 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 17169 T1027 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 17179 T1027 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 17793 T973 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {checkLive=true&nodeName=127.0.0.1:36333_qkk&state=recovering&core=collection1&version=2&onlyIfLeader=true&wt=javabin&action=PREPRECOVERY&coreNodeName=4} status=0 QTime=2000
[junit4:junit4] 2> 18071 T1027 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 18078 T1027 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 18085 T1027 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 18098 T1027 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 18102 T1027 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 18106 T1027 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 18107 T1027 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 18108 T1027 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 18108 T1027 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 18109 T1027 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 18110 T1027 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 18110 T1027 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 18114 T1027 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1363832648410/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty4/
[junit4:junit4] 2> 18115 T1027 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@89c25c
[junit4:junit4] 2> 18115 T1027 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 18116 T1027 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty4 forceNew: false
[junit4:junit4] 2> 18116 T1027 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty4/index/
[junit4:junit4] 2> 18117 T1027 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 18117 T1027 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty4/index forceNew: false
[junit4:junit4] 2> 18119 T1027 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@11d4ca0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16f34b5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 18119 T1027 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 18122 T1027 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 18122 T1027 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 18123 T1027 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 18124 T1027 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 18124 T1027 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 18125 T1027 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 18125 T1027 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 18126 T1027 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 18126 T1027 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 18130 T1027 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 18134 T1027 oass.SolrIndexSearcher.<init> Opening Searcher@147b0fa main
[junit4:junit4] 2> 18135 T1027 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty4/tlog
[junit4:junit4] 2> 18135 T1027 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 18136 T1027 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 18141 T1028 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@147b0fa main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 18143 T1027 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 18144 T1027 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 18595 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 18596 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44576/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:44576_qkk",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 18602 T958 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 18602 T958 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 18608 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18608 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18608 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18608 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18608 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18608 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19145 T1027 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 19146 T1027 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44576/qkk collection:collection1 shard:shard2
[junit4:junit4] 2> 19150 T1027 oasc.ZkController.register We are http://127.0.0.1:44576/qkk/collection1/ and leader is http://127.0.0.1:49791/qkk/collection1/
[junit4:junit4] 2> 19150 T1027 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44576/qkk
[junit4:junit4] 2> 19151 T1027 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 19151 T1027 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C57 name=collection1 org.apache.solr.core.SolrCore@b29657 url=http://127.0.0.1:44576/qkk/collection1 node=127.0.0.1:44576_qkk C57_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:44576/qkk, collection=collection1, core=collection1, state=down, node_name=127.0.0.1:44576_qkk}
[junit4:junit4] 2> 19151 T1029 C57 P44576 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 19152 T1027 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19153 T1029 C57 P44576 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 19153 T1029 C57 P44576 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 19153 T1029 C57 P44576 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 19154 T935 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 19155 T1029 C57 P44576 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 19155 T935 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 19156 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 19162 T935 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19164 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 19171 T973 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131/onenodecollectioncore
[junit4:junit4] 2> 19171 T973 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4] 2> 19172 T973 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4] 2> 19173 T973 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 19174 T973 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 19175 T973 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4] 2> 19179 T973 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4] 2> 19180 T973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131/onenodecollectioncore/'
[junit4:junit4] 2> 19226 T973 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 19293 T973 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 19294 T973 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 19302 T973 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> C56_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:36333/qkk, collection=collection1, core=collection1, state=recovering, node_name=127.0.0.1:36333_qkk, shard=shard1}
[junit4:junit4] 2> 19794 T1012 C56 P36333 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:37815/qkk/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 19795 T1012 C56 P36333 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:36333/qkk START replicas=[http://127.0.0.1:37815/qkk/collection1/] nUpdates=100
[junit4:junit4] 2> 19795 T1012 C56 P36333 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 19796 T1012 C56 P36333 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 19797 T1012 C56 P36333 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 19797 T1012 C56 P36333 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 19797 T1012 C56 P36333 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 19797 T1012 C56 P36333 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:37815/qkk/collection1/. core=collection1
[junit4:junit4] 2> 19798 T1012 C56 P36333 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C58 name=collection1 org.apache.solr.core.SolrCore@43ca95 url=http://127.0.0.1:37815/qkk/collection1 node=127.0.0.1:37815_qkk C58_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:37815/qkk, collection=collection1, core=collection1, state=active, node_name=127.0.0.1:37815_qkk, shard=shard1, leader=true}
[junit4:junit4] 2> 19807 T971 C58 P37815 REQ /get {distrib=false&getVersions=100&version=2&qt=/get&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 19820 T972 C58 P37815 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 19823 T972 C58 P37815 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f991bd lockFactory=org.apache.lucene.store.NativeFSLockFactory@1e58434),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 19824 T972 C58 P37815 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 19825 T972 C58 P37815 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f991bd lockFactory=org.apache.lucene.store.NativeFSLockFactory@1e58434),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f991bd lockFactory=org.apache.lucene.store.NativeFSLockFactory@1e58434),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 19826 T972 C58 P37815 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 19827 T972 C58 P37815 oass.SolrIndexSearcher.<init> Opening Searcher@551c94 realtime
[junit4:junit4] 2> 19827 T972 C58 P37815 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 19828 T972 C58 P37815 /update {commit=true&version=2&waitSearcher=true&softCommit=false&openSearcher=false&commit_end_point=true&wt=javabin} {commit=} 0 8
[junit4:junit4] 2> 19829 T1012 C56 P36333 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 19830 T1012 C56 P36333 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 19842 T971 C58 P37815 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 19842 T971 C58 P37815 REQ /replication {command=indexversion&version=2&qt=/replication&wt=javabin} status=0 QTime=11
[junit4:junit4] 2> 19843 T1012 C56 P36333 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 19844 T1012 C56 P36333 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 19844 T1012 C56 P36333 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 19846 T972 C58 P37815 REQ /replication {generation=2&command=filelist&version=2&qt=/replication&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 19847 T1012 C56 P36333 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 19849 T1012 C56 P36333 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty3/index.20130321032412467 forceNew: false
[junit4:junit4] 2> 19849 T1012 C56 P36333 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@2bd3e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@380559) fullCopy=false
[junit4:junit4] 2> 19852 T970 C58 P37815 REQ /replication {generation=2&checksum=true&command=filecontent&qt=/replication&wt=filestream&file=segments_2} status=0 QTime=0
[junit4:junit4] 2> 19860 T1012 C56 P36333 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 19863 T1012 C56 P36333 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 19864 T1012 C56 P36333 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 19866 T1012 C56 P36333 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1304cd5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1afa091),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1304cd5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1afa091),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 19867 T1012 C56 P36333 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 19868 T1012 C56 P36333 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 19868 T1012 C56 P36333 oass.SolrIndexSearcher.<init> Opening Searcher@48e611 main
[junit4:junit4] 2> 19870 T1011 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@48e611 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 19871 T1012 C56 P36333 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 19872 T1012 C56 P36333 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 19872 T1012 C56 P36333 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 19872 T1012 C56 P36333 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 19880 T1012 C56 P36333 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 20113 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20114 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44576/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "node_name":"127.0.0.1:44576_qkk",
[junit4:junit4] 2> "shard":"shard2"}
[junit4:junit4] 2> 20117 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36333/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "node_name":"127.0.0.1:36333_qkk",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 20124 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20124 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20124 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20124 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20124 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20124 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20128 T973 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 20140 T973 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 20146 T973 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 20163 T986 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {checkLive=true&nodeName=127.0.0.1:44576_qkk&state=recovering&core=collection1&version=2&onlyIfLeader=true&wt=javabin&action=PREPRECOVERY&coreNodeName=5} status=0 QTime=1001
[junit4:junit4] 2> 20163 T973 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 20169 T973 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 20180 T973 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 20182 T973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 20183 T973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 20184 T973 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 20186 T973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 20187 T973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 20188 T973 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 20188 T973 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363832636131/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626/onenodecollection/
[junit4:junit4] 2> 20189 T973 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@89c25c
[junit4:junit4] 2> 20190 T973 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 20191 T973 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626/onenodecollection forceNew: false
[junit4:junit4] 2> 20192 T973 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626/onenodecollection/index/
[junit4:junit4] 2> 20193 T973 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 20194 T973 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626/onenodecollection/index forceNew: false
[junit4:junit4] 2> 20197 T973 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5a1eed lockFactory=org.apache.lucene.store.NativeFSLockFactory@afb03e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 20197 T973 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 20200 T973 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 20201 T973 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 20202 T973 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 20203 T973 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 20204 T973 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 20205 T973 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 20206 T973 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 20207 T973 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 20208 T973 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 20211 T973 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 20213 T973 oass.SolrIndexSearcher.<init> Opening Searcher@1d22dd0 main
[junit4:junit4] 2> 20214 T973 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626/onenodecollection/tlog
[junit4:junit4] 2> 20214 T973 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 20215 T973 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 20220 T1033 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@1d22dd0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 20221 T973 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 21631 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 21633 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37815/qkk",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:37815_qkk",
[junit4:junit4] 2> "shard":null}
[junit4:junit4] 2> 21633 T958 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4] 2> 21633 T958 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 21649 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 21649 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 21649 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 21649 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 21649 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 21649 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> C57_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:44576/qkk, collection=collection1, core=collection1, state=recovering, node_name=127.0.0.1:44576_qkk, shard=shard2}
[junit4:junit4] 2> 22164 T1029 C57 P44576 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:49791/qkk/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 22164 T1029 C57 P44576 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:44576/qkk START replicas=[http://127.0.0.1:49791/qkk/collection1/] nUpdates=100
[junit4:junit4] 2> 22165 T1029 C57 P44576 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 22165 T1029 C57 P44576 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 22166 T1029 C57 P44576 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 22166 T1029 C57 P44576 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 22166 T1029 C57 P44576 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 22167 T1029 C57 P44576 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:49791/qkk/collection1/. core=collection1
[junit4:junit4] 2> 22167 T1029 C57 P44576 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C59 name=collection1 org.apache.solr.core.SolrCore@9ed7dc url=http://127.0.0.1:49791/qkk/collection1 node=127.0.0.1:49791_qkk C59_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:49791/qkk, collection=collection1, core=collection1, state=active, node_name=127.0.0.1:49791_qkk, shard=shard2, leader=true}
[junit4:junit4] 2> 22175 T987 C59 P49791 REQ /get {distrib=false&getVersions=100&version=2&qt=/get&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 22175 T989 C59 P49791 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 22177 T989 C59 P49791 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@149c5b3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6c0c2),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 22178 T989 C59 P49791 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 22179 T989 C59 P49791 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@149c5b3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6c0c2),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@149c5b3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6c0c2),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 22180 T989 C59 P49791 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 22181 T989 C59 P49791 oass.SolrIndexSearcher.<init> Opening Searcher@1291a6b realtime
[junit4:junit4] 2> 22182 T989 C59 P49791 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 22182 T989 C59 P49791 /update {commit=true&version=2&waitSearcher=true&softCommit=false&openSearcher=false&commit_end_point=true&wt=javabin} {commit=} 0 7
[junit4:junit4] 2> 22183 T1029 C57 P44576 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 22183 T1029 C57 P44576 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 22185 T986 C59 P49791 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 22186 T986 C59 P49791 REQ /replication {command=indexversion&version=2&qt=/replication&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 22187 T1029 C57 P44576 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 22187 T1029 C57 P44576 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 22187 T1029 C57 P44576 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 22189 T987 C59 P49791 REQ /replication {generation=2&command=filelist&version=2&qt=/replication&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 22190 T1029 C57 P44576 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 22192 T1029 C57 P44576 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty4/index.20130321032414810 forceNew: false
[junit4:junit4] 2> 22192 T1029 C57 P44576 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@151138 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1bcb068) fullCopy=false
[junit4:junit4] 2> 22200 T989 C59 P49791 REQ /replication {generation=2&checksum=true&command=filecontent&qt=/replication&wt=filestream&file=segments_2} status=0 QTime=0
[junit4:junit4] 2> 22202 T1029 C57 P44576 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 22203 T1029 C57 P44576 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 22203 T1029 C57 P44576 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 22205 T1029 C57 P44576 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@11d4ca0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16f34b5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@11d4ca0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16f34b5),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 22206 T1029 C57 P44576 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 22206 T1029 C57 P44576 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 22207 T1029 C57 P44576 oass.SolrIndexSearcher.<init> Opening Searcher@1570248 main
[junit4:junit4] 2> 22208 T1028 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1570248 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 22209 T1029 C57 P44576 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 22209 T1029 C57 P44576 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 22210 T1029 C57 P44576 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 22210 T1029 C57 P44576 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 22211 T1029 C57 P44576 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 22223 T973 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4] 2> 22224 T973 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:37815/qkk collection:onenodecollection shard:shard1
[junit4:junit4] 2> 22225 T973 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4] 2> 22233 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:delete cxid:0xae zxid:0xc4 txntype:-1 reqpath:n/a Error Path:/solr/collections/onenodecollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/onenodecollection/leaders
[junit4:junit4] 2> 22234 T973 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 22235 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:create cxid:0xaf zxid:0xc5 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22238 T973 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 22238 T973 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 22239 T973 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37815/qkk/onenodecollectioncore/
[junit4:junit4] 2> 22239 T973 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 22240 T973 oasc.SyncStrategy.syncToMe http://127.0.0.1:37815/qkk/onenodecollectioncore/ has no replicas
[junit4:junit4] 2> 22241 T973 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37815/qkk/onenodecollectioncore/
[junit4:junit4] 2> 22241 T973 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4] 2> 22247 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:create cxid:0xba zxid:0xc9 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 23155 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 23156 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:44576/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "node_name":"127.0.0.1:44576_qkk",
[junit4:junit4] 2> "shard":"shard2"}
[junit4:junit4] 2> 23174 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 23174 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 23174 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 23174 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 23174 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 23174 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 23202 T973 oasc.ZkController.register We are http://127.0.0.1:37815/qkk/onenodecollectioncore/ and leader is http://127.0.0.1:37815/qkk/onenodecollectioncore/
[junit4:junit4] 2> 23202 T973 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:37815/qkk
[junit4:junit4] 2> 23203 T973 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 23203 T973 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4] 2> 23206 T973 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 23207 T973 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {numShards=1&roles=none&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626/onenodecollection&collection=onenodecollection&version=2&wt=javabin&action=CREATE&name=onenodecollectioncore} status=0 QTime=4037
[junit4:junit4] 2> 23208 T935 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 23209 T935 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 24212 T935 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 24685 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 24686 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37815/qkk",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:37815_qkk_onenodecollectioncore",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "node_name":"127.0.0.1:37815_qkk",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 24691 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 24692 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 24691 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 24691 T964 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 24691 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 24692 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 25214 T935 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 25215 T935 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4] 2> 25216 T935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 25225 T935 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:44044 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4da31a
[junit4:junit4] 2> 25226 T935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 25226 T1036 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:44044. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 25227 T1036 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:44044, initiating session
[junit4:junit4] 2> 25227 T937 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:53322
[junit4:junit4] 2> 25227 T937 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:53322
[junit4:junit4] 2> 25227 T939 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8ac27538000d with negotiated timeout 10000 for client /127.0.0.1:53322
[junit4:junit4] 2> 25228 T1036 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:44044, sessionid = 0x13d8ac27538000d, negotiated timeout = 10000
[junit4:junit4] 2> 25228 T1037 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4da31a name:ZooKeeperConnection Watcher:127.0.0.1:44044 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 25228 T935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 25260 T940 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8ac27538000d
[junit4:junit4] 2> 25260 T1037 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 25260 T937 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:53322 which had sessionid 0x13d8ac27538000d
[junit4:junit4] 2> 25260 T935 oaz.ZooKeeper.close Session: 0x13d8ac27538000d closed
[junit4:junit4] 2> 25261 T940 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8ac275380004
[junit4:junit4] 2> 25262 T964 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 25262 T935 oaz.ZooKeeper.close Session: 0x13d8ac275380004 closed
[junit4:junit4] 2> 25262 T937 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:53271 which had sessionid 0x13d8ac275380004
[junit4:junit4] 2> 25264 T935 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 46503
[junit4:junit4] 2> 25264 T935 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=5257805
[junit4:junit4] 2> 26198 T958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 26199 T958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:46503/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:46503_qkk",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 26204 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 26204 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 26204 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 26204 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 26204 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 27265 T935 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 27266 T935 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 27276 T935 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@7cd92c
[junit4:junit4] 2> 27282 T935 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 27283 T935 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 27284 T935 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 27284 T935 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 27285 T935 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 27286 T935 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/control/data
[junit4:junit4] 2> 27287 T935 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/control/data
[junit4:junit4] 2> 27287 T935 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/control/data/index
[junit4:junit4] 2> 27288 T935 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/control/data/index
[junit4:junit4] 2> 27289 T958 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89380135412170755-127.0.0.1:46503_qkk-n_0000000000) am no longer a leader.
[junit4:junit4] 2> 27290 T940 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8ac275380003
[junit4:junit4] 2> 27292 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 27292 T937 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:53270 which had sessionid 0x13d8ac275380003
[junit4:junit4] 2> 27292 T935 oaz.ZooKeeper.close Session: 0x13d8ac275380003 closed
[junit4:junit4] 2> 27293 T993 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 27293 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:delete cxid:0xc8 zxid:0xe4 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 27293 T1009 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 27294 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 27295 T1026 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 27294 T977 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 27294 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 27298 T977 oasc.Overseer.start Overseer (id=89380135412170758-127.0.0.1:37815_qkk-n_0000000001) starting
[junit4:junit4] 2> 27298 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:create cxid:0xcd zxid:0xe6 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 27300 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:create cxid:0xce zxid:0xe7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 27301 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:create cxid:0xd0 zxid:0xe8 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 27303 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380006 type:create cxid:0xd2 zxid:0xe9 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 27305 T1039 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 27306 T977 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 27306 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 27307 T1038 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 27310 T1038 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 27311 T1038 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:46503/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:46503_qkk",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 27315 T935 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/qkk,null}
[junit4:junit4] 2> 27317 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 27317 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 27317 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 27317 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 27368 T935 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 37815
[junit4:junit4] 2> 27369 T935 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=28875518
[junit4:junit4] 2> 28592 T957 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 28593 T957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 28593 T957 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 28593 T957 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 28823 T1038 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 28824 T1038 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37815/qkk",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:37815_qkk_onenodecollectioncore",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:37815_qkk",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 28828 T1038 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37815/qkk",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:37815_qkk",
[junit4:junit4] 2> "shard":"shard1"}
[junit4:junit4] 2> 28838 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 28838 T993 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 28838 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 28838 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 30372 T935 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 30373 T935 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 30375 T935 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 30379 T935 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@43ca95
[junit4:junit4] 2> 30385 T935 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}
[junit4:junit4] 2> 30385 T935 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 30386 T935 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 30387 T935 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 30389 T935 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 30390 T935 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty1
[junit4:junit4] 2> 30391 T935 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty1
[junit4:junit4] 2> 30391 T935 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty1/index
[junit4:junit4] 2> 30392 T935 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363832632626/jetty1/index
[junit4:junit4] 2> 30393 T935 oasc.SolrCore.close [onenodecollectioncore] CLOSING SolrCore org.apache.solr.core.SolrCore@100871d
[junit4:junit4] 2> 30408 T935 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 30409 T935 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 30409 T935 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 30410 T935 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 30411 T935 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4] 2> 30412 T935 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626/onenodecollection
[junit4:junit4] 2> 30413 T935 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626/onenodecollection
[junit4:junit4] 2> 30413 T935 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626/onenodecollection/index
[junit4:junit4] 2> 30414 T935 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363832632626/onenodecollection/index
[junit4:junit4] 2> 30416 T1038 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89380135412170758-127.0.0.1:37815_qkk-n_0000000001) am no longer a leader.
[junit4:junit4] 2> 30416 T940 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8ac275380006
[junit4:junit4] 2> 30419 T977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 30419 T937 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:53273 which had sessionid 0x13d8ac275380006
[junit4:junit4] 2> 30419 T977 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 30419 T935 oaz.ZooKeeper.close Session: 0x13d8ac275380006 closed
[junit4:junit4] 2> 30420 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac27538000a type:delete cxid:0x60 zxid:0xfa txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard1
[junit4:junit4] 2> 30420 T1026 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 30420 T977 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 30421 T1009 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 30421 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380008 type:delete cxid:0x7e zxid:0xfb txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 30422 T977 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 30421 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 30423 T993 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 30422 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac27538000a type:create cxid:0x61 zxid:0xfc txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 30426 T1009 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 30426 T993 oasc.Overseer.start Overseer (id=89380135412170760-127.0.0.1:49791_qkk-n_0000000002) starting
[junit4:junit4] 2> 30426 T1009 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 30427 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8ac275380008 type:create cxid:0x83 zxid:0xff txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 30427 T1009 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 30428 T1009 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36333/qkk/collection1/
[junit4:junit4] 2> 30428 T1009 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:36333/qkk START replicas=[http://127.0.0.1:37815/qkk/collection1/] nUpdates=100
[junit4:junit4] 2> 30428 T940 oazs.PrepRequestProcessor.pRequest Got user-level KeeperEx
[...truncated too long message...]
ope/Monaco -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 33.9s J1 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.common.SolrException: Server at http://127.0.0.1:49791/qkk/onenodecollectioncore returned non ok status:404, message:Can not find: /qkk/onenodecollectioncore/update
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([7CDEF2EA1AD216F6:FD387CF26D8D76CA]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:375)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4:junit4] > at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4:junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
[junit4:junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
[junit4:junit4] > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4] > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4] > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4] > at java.lang.reflect.Method.invoke(Method.java:487)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4] > at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4] > at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4] > at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4] > at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4] > at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4] > at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4] > at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4] > at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4] > at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4] > at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4] > at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 33897 T935 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 33901 T934 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4:junit4] 2> 33938 T1009 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 33939 T1009 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 33939 T1009 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 33939 T1009 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 34381 T938 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4] 2> 35052 T1026 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 35053 T1026 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 35053 T1026 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 35053 T1026 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=DefaultSimilarity, locale=fr_BE, timezone=Europe/Monaco
[junit4:junit4] 2> NOTE: Linux 3.2.0-39-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=2,free=12482872,total=69541888
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestDynamicFieldCollectionResource, TestUtils, EchoParamsTest, HardAutoCommitTest, TestSolrDiscoveryProperties, OpenExchangeRatesOrgProviderTest, LeaderElectionIntegrationTest, DOMUtilTest, IndexReaderFactoryTest, TestDistributedGrouping, CurrencyFieldXmlFileTest, TestComponentsName, DefaultValueUpdateProcessorTest, ZkNodePropsTest, HighlighterConfigTest, SuggesterTSTTest, SolrCmdDistributorTest, TestQuerySenderNoQuery, TestDFRSimilarityFactory, ClusterStateTest, CopyFieldTest, TestFoldingMultitermQuery, TestFastOutputStream, TestUpdate, HighlighterTest, StandardRequestHandlerTest, TestOmitPositions, TestFieldTypeCollectionResource, TestCopyFieldCollectionResource, TestZkChroot, CollectionsAPIDistributedZkTest, DirectUpdateHandlerTest, TermVectorComponentDistributedTest, JSONWriterTest, TestCSVLoader, CurrencyFieldOpenExchangeTest, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 35.23s, 1 test, 1 error <<< FAILURES!
[...truncated 636 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:375: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:355: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1210: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:874: There were test failures: 272 suites, 1144 tests, 1 error, 13 ignored (7 assumptions)
Total time: 44 minutes 34 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/jdk1.8.0-ea-b79 -client -XX:+UseConcMarkSweepGC
Email was triggered for: Failure
Sending email for trigger: Failure