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 2014/03/08 04:30:05 UTC

[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.8.0-fcs-b132) - Build # 9606 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9606/
Java: 32bit/jdk1.8.0-fcs-b132 -client -XX:+UseSerialGC

1 tests failed.
REGRESSION:  org.apache.solr.client.solrj.impl.CloudSolrServerTest.testShutdown

Error Message:
java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:51009 within 45000 ms

Stack Trace:
org.apache.solr.common.SolrException: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:51009 within 45000 ms
	at __randomizedtesting.SeedInfo.seed([F95370E2A9F9DF8D:1A2579774E834AFF]:0)
	at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:150)
	at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:101)
	at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:91)
	at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:89)
	at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:83)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.setUp(AbstractDistribZkTestBase.java:70)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.setUp(AbstractFullDistribZkTestBase.java:200)
	at org.apache.solr.client.solrj.impl.CloudSolrServerTest.setUp(CloudSolrServerTest.java:78)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:483)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:771)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:744)
Caused by: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:51009 within 45000 ms
	at org.apache.solr.common.cloud.ConnectionManager.waitForConnected(ConnectionManager.java:223)
	at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:142)
	... 46 more




Build Log:
[...truncated 11836 lines...]
   [junit4] Suite: org.apache.solr.client.solrj.impl.CloudSolrServerTest
   [junit4]   2> 4773 T37 oas.SolrTestCaseJ4.startTrackingSearchers WARN startTrackingSearchers: numOpens=7 numCloses=7
   [junit4]   2> 4774 T37 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 4775 T37 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 4777 T37 oasc.AbstractZkTestCase.<clinit> WARN TEST_HOME() does not exist - solrj test?
   [junit4]   2> 4782 T37 oas.SolrTestCaseJ4.setUp ###Starting testShutdown
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./solrtest-CloudSolrServerTest-1394249302685
   [junit4]   2> 4784 T37 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 4787 T38 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 4886 T37 oasc.ZkTestServer.run start zk server on port:51009
   [junit4]   2> 4940 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 59412 T41 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 54122ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 59414 T37 oas.SolrTestCaseJ4.tearDown ###Ending testShutdown
   [junit4]   2> 59424 T39 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1449fbc02ee0000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 59425 T37 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51009 51009
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=CloudSolrServerTest -Dtests.method=testShutdown -Dtests.seed=F95370E2A9F9DF8D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_NI -Dtests.timezone=Africa/Cairo -Dtests.file.encoding=UTF-8
   [junit4] ERROR   55.0s J0 | CloudSolrServerTest.testShutdown <<<
   [junit4]    > Throwable #1: org.apache.solr.common.SolrException: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:51009 within 45000 ms
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([F95370E2A9F9DF8D:1A2579774E834AFF]:0)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:150)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:101)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:91)
   [junit4]    > 	at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:89)
   [junit4]    > 	at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:83)
   [junit4]    > 	at org.apache.solr.cloud.AbstractDistribZkTestBase.setUp(AbstractDistribZkTestBase.java:70)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.setUp(AbstractFullDistribZkTestBase.java:200)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.CloudSolrServerTest.setUp(CloudSolrServerTest.java:78)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]    > Caused by: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:51009 within 45000 ms
   [junit4]    > 	at org.apache.solr.common.cloud.ConnectionManager.waitForConnected(ConnectionManager.java:223)
   [junit4]    > 	at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:142)
   [junit4]    > 	... 46 more
   [junit4]   2> 59739 T37 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./solrtest-CloudSolrServerTest-1394249357641
   [junit4]   2> 59739 T37 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 59740 T45 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 59840 T37 oasc.ZkTestServer.run start zk server on port:46172
   [junit4]   2> 59841 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 59901 T51 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@122dcce name:ZooKeeperConnection Watcher:127.0.0.1:46172 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 59902 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 59903 T37 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 59922 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 59924 T53 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c3fee6 name:ZooKeeperConnection Watcher:127.0.0.1:46172/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 59925 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 59930 T37 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 59936 T37 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 59940 T37 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 59944 T37 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 59948 T37 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 59949 T37 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 59956 T37 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 59957 T37 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 59970 T37 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml because it doesn't exist
   [junit4]   2> 59971 T37 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/stopwords.txt because it doesn't exist
   [junit4]   2> 59971 T37 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/protwords.txt because it doesn't exist
   [junit4]   2> 59971 T37 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/currency.xml because it doesn't exist
   [junit4]   2> 59972 T37 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/enumsConfig.xml because it doesn't exist
   [junit4]   2> 59972 T37 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/open-exchange-rates.json because it doesn't exist
   [junit4]   2> 59972 T37 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/mapping-ISOLatin1Accent.txt because it doesn't exist
   [junit4]   2> 59973 T37 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/old_synonyms.txt because it doesn't exist
   [junit4]   2> 59973 T37 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/synonyms.txt because it doesn't exist
   [junit4]   2> 59978 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 59980 T55 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12d0e79 name:ZooKeeperConnection Watcher:127.0.0.1:46172/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 59980 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 60148 T37 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 60368 T37 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 60386 T37 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:48821
   [junit4]   2> 60407 T37 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 60408 T37 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 60408 T37 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1394249357885
   [junit4]   2> 60408 T37 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1394249357885/'
   [junit4]   2> 60427 T37 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1394249357885/solr.xml
   [junit4]   2> 60442 T37 oasc.CoreContainer.<init> New CoreContainer 30140397
   [junit4]   2> 60443 T37 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1394249357885/]
   [junit4]   2> 60444 T37 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 60444 T37 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 60444 T37 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 60445 T37 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 60445 T37 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 60445 T37 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 60446 T37 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 60446 T37 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 60446 T37 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 60451 T37 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 60451 T37 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 60451 T37 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 60452 T37 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46172/solr
   [junit4]   2> 60461 T37 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 60462 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 60465 T67 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1eb1619 name:ZooKeeperConnection Watcher:127.0.0.1:46172 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 60465 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 60471 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 60473 T69 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c4b642 name:ZooKeeperConnection Watcher:127.0.0.1:46172/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 60474 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 60480 T37 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 60487 T37 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 60502 T37 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 60504 T37 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48821_
   [junit4]   2> 60507 T37 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48821_
   [junit4]   2> 60511 T37 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 60513 T37 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 60521 T37 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48821_
   [junit4]   2> 60521 T37 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 60525 T37 oasc.Overseer.start Overseer (id=91373525902819332-127.0.0.1:48821_-n_0000000000) starting
   [junit4]   2> 60543 T37 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 60565 T71 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 60565 T37 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 60566 T71 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 60569 T37 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 60571 T37 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 60578 T70 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 60583 T72 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 60584 T72 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 60587 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 60587 T72 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 60590 T70 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 60591 T70 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:48821",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:48821_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 60591 T70 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 60598 T70 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 60602 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 60605 T69 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 61588 T72 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 61588 T72 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1394249357885/collection1
   [junit4]   2> 61589 T72 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 61589 T72 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 61590 T72 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 61591 T72 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 61592 T72 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1394249357885/collection1/'
   [junit4]   2> 61629 T72 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 61641 T72 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 61643 T72 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 61684 T72 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 61720 T72 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [solr.SortableIntField]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 61726 T72 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [solr.SortableLongField]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 61730 T72 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [solr.SortableFloatField]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 61734 T72 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [solr.SortableDoubleField]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 61980 T72 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 61981 T72 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 61984 T72 oass.IndexSchema.readSchema WARN Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2)
   [junit4]   2> 61984 T72 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (3)
   [junit4]   2> 61988 T72 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 61988 T72 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1394249357885/collection1/, dataDir=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/control/data/
   [junit4]   2> 61988 T72 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 61989 T72 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/control/data
   [junit4]   2> 61989 T72 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/control/data/index/
   [junit4]   2> 61989 T72 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 61998 T72 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/control/data/index
   [junit4]   2> 62001 T72 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/index6063160631tmp lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/control/data/index),segFN=segments_1,generation=1}
   [junit4]   2> 62001 T72 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 62002 T72 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 62006 T72 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 62006 T72 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 62007 T72 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 62008 T72 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 62008 T72 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 62008 T72 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 62013 T72 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
   [junit4]   2> 62014 T72 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 62015 T72 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 62016 T72 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 62021 T72 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/index6063160631tmp lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/control/data/index),segFN=segments_1,generation=1}
   [junit4]   2> 62021 T72 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 62022 T72 oass.SolrIndexSearcher.<init> Opening Searcher@b69a9[collection1] main
   [junit4]   2> 62023 T73 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b69a9[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 62023 T72 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 62024 T37 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0
   [junit4]   2> 62024 T76 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:48821 collection:control_collection shard:shard1
   [junit4]   2> 62024 T37 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 62030 T76 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 62034 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 62036 T78 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cb4153 name:ZooKeeperConnection Watcher:127.0.0.1:46172/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 62036 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 62038 T37 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 62040 T76 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 62043 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 62043 T37 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 62044 T76 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 62044 T76 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 62049 T70 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> ASYNC  NEW_CORE C6 name=collection1 org.apache.solr.core.SolrCore@1e4e56 url=https://127.0.0.1:48821/collection1 node=127.0.0.1:48821_ C6_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:48821, core=collection1, node_name=127.0.0.1:48821_}
   [junit4]   2> 62050 T76 C6 P48821 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:48821/collection1/
   [junit4]   2> 62050 T76 C6 P48821 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 62050 T76 C6 P48821 oasc.SyncStrategy.syncToMe https://127.0.0.1:48821/collection1/ has no replicas
   [junit4]   2> 62051 T76 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:48821/collection1/ shard1
   [junit4]   2> 62052 T76 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 62054 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 62062 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 62072 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 62079 T37 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 62080 T37 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 62084 T37 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 62087 T37 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:40997
   [junit4]   2> 62088 T37 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 62089 T37 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 62089 T37 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1394249359945
   [junit4]   2> 62089 T37 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1394249359945/'
   [junit4]   2> 62103 T37 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1394249359945/solr.xml
   [junit4]   2> 62122 T37 oasc.CoreContainer.<init> New CoreContainer 29923529
   [junit4]   2> 62123 T37 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1394249359945/]
   [junit4]   2> 62123 T37 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 62124 T37 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 62124 T37 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 62125 T37 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 62125 T37 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 62126 T37 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 62126 T37 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 62126 T37 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 62127 T37 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 62131 T37 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 62132 T37 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 62132 T37 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 62132 T37 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46172/solr
   [junit4]   2> 62133 T37 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 62133 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 62136 T89 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1651615 name:ZooKeeperConnection Watcher:127.0.0.1:46172 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 62136 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 62139 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 62140 T91 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@196a92c name:ZooKeeperConnection Watcher:127.0.0.1:46172/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 62141 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 62147 T37 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 62175 T69 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 62175 T91 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 62175 T78 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 62214 T76 oasc.ZkController.register We are https://127.0.0.1:48821/collection1/ and leader is https://127.0.0.1:48821/collection1/
   [junit4]   2> 62214 T76 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:48821
   [junit4]   2> 62214 T76 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 62215 T76 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 62215 T76 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 62216 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 62217 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 62217 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 62217 T76 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 62219 T70 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 62220 T70 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:48821",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:48821_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 62224 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 62326 T91 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 62326 T69 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 62326 T78 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 63151 T37 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40997_
   [junit4]   2> 63154 T37 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40997_
   [junit4]   2> 63157 T78 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 63157 T69 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 63157 T91 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 63166 T92 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 63166 T92 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 63167 T92 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 63167 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 63167 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 63168 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 63170 T70 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 63171 T70 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:40997",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:40997_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 63171 T70 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 63171 T70 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 63174 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 63379 T91 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 63379 T69 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 63379 T78 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 64167 T92 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 64168 T92 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1394249359945/collection1
   [junit4]   2> 64168 T92 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 64169 T92 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 64169 T92 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 64170 T92 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 64171 T92 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1394249359945/collection1/'
   [junit4]   2> 64208 T92 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 64220 T92 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 64224 T92 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 64241 T92 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 64389 T92 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 64391 T92 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 64393 T92 oass.IndexSchema.readSchema WARN Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2)
   [junit4]   2> 64394 T92 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (3)
   [junit4]   2> 64395 T92 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 64395 T92 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1394249359945/collection1/, dataDir=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty1/
   [junit4]   2> 64396 T92 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 64396 T92 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty1
   [junit4]   2> 64397 T92 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty1/index/
   [junit4]   2> 64397 T92 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 64398 T92 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty1/index
   [junit4]   2> 64402 T92 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/index6063160632tmp lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty1/index),segFN=segments_1,generation=1}
   [junit4]   2> 64402 T92 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 64404 T92 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 64404 T92 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 64405 T92 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 64405 T92 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 64405 T92 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 64406 T92 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 64406 T92 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 64407 T92 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
   [junit4]   2> 64409 T92 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 64410 T92 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 64411 T92 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 64413 T92 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/index6063160632tmp lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty1/index),segFN=segments_1,generation=1}
   [junit4]   2> 64413 T92 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 64414 T92 oass.SolrIndexSearcher.<init> Opening Searcher@12bca45[collection1] main
   [junit4]   2> 64415 T92 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 64415 T93 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@12bca45[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 64416 T37 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0
   [junit4]   2> 64416 T37 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 64417 T96 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:40997 collection:collection1 shard:shard2
   [junit4]   2> 64420 T96 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 64436 T96 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 64438 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 64438 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 64439 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 64439 T96 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 64440 T96 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C7 name=collection1 org.apache.solr.core.SolrCore@6821cf url=https://127.0.0.1:40997/collection1 node=127.0.0.1:40997_ C7_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:40997, core=collection1, node_name=127.0.0.1:40997_}
   [junit4]   2> 64440 T96 C7 P40997 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:40997/collection1/
   [junit4]   2> 64440 T96 C7 P40997 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 64441 T96 C7 P40997 oasc.SyncStrategy.syncToMe https://127.0.0.1:40997/collection1/ has no replicas
   [junit4]   2> 64441 T96 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:40997/collection1/ shard2
   [junit4]   2> 64441 T70 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 64442 T96 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 64447 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 64454 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 64462 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 64462 T37 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 64463 T37 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 64468 T37 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 64472 T37 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:35104
   [junit4]   2> 64475 T37 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 64475 T37 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 64475 T37 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1394249362321
   [junit4]   2> 64476 T37 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1394249362321/'
   [junit4]   2> 64497 T37 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1394249362321/solr.xml
   [junit4]   2> 64517 T37 oasc.CoreContainer.<init> New CoreContainer 21705244
   [junit4]   2> 64518 T37 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1394249362321/]
   [junit4]   2> 64518 T37 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 64519 T37 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 64519 T37 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 64520 T37 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 64520 T37 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 64521 T37 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 64521 T37 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 64522 T37 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 64522 T37 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 64530 T37 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 64530 T37 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 64531 T37 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 64531 T37 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46172/solr
   [junit4]   2> 64532 T37 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 64533 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 64535 T107 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ab53d6 name:ZooKeeperConnection Watcher:127.0.0.1:46172 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 64535 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 64538 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 64539 T109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@308b39 name:ZooKeeperConnection Watcher:127.0.0.1:46172/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 64539 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 64544 T37 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 64566 T78 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 64566 T69 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 64566 T109 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 64566 T91 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 64603 T96 oasc.ZkController.register We are https://127.0.0.1:40997/collection1/ and leader is https://127.0.0.1:40997/collection1/
   [junit4]   2> 64604 T96 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:40997
   [junit4]   2> 64604 T96 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 64604 T96 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 64604 T96 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 64606 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 64606 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 64606 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 64607 T96 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 64610 T70 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 64611 T70 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:40997",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:40997_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 64614 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 64718 T109 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 64718 T69 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 64718 T78 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 64718 T91 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 65548 T37 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35104_
   [junit4]   2> 65549 T37 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35104_
   [junit4]   2> 65552 T109 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 65552 T78 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 65552 T91 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 65553 T69 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 65559 T110 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 65559 T110 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 65560 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 65560 T110 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 65560 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 65561 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 65563 T70 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 65564 T70 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:35104",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:35104_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 65564 T70 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 65564 T70 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 65567 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 65670 T78 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 65671 T69 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 65670 T91 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 65670 T109 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 66561 T110 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 66561 T110 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1394249362321/collection1
   [junit4]   2> 66562 T110 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 66562 T110 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 66563 T110 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 66564 T110 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 66564 T110 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1394249362321/collection1/'
   [junit4]   2> 66596 T110 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 66609 T110 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 66611 T110 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 66626 T110 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 66753 T110 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 66754 T110 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 66755 T110 oass.IndexSchema.readSchema WARN Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2)
   [junit4]   2> 66756 T110 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (3)
   [junit4]   2> 66757 T110 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 66757 T110 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1394249362321/collection1/, dataDir=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty2/
   [junit4]   2> 66757 T110 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 66758 T110 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty2
   [junit4]   2> 66758 T110 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty2/index/
   [junit4]   2> 66758 T110 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 66759 T110 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty2/index
   [junit4]   2> 66761 T110 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/index6063160633tmp lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty2/index),segFN=segments_1,generation=1}
   [junit4]   2> 66761 T110 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 66762 T110 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 66762 T110 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 66763 T110 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 66763 T110 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 66763 T110 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 66763 T110 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 66764 T110 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 66764 T110 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
   [junit4]   2> 66765 T110 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 66766 T110 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 66767 T110 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 66768 T110 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/index6063160633tmp lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty2/index),segFN=segments_1,generation=1}
   [junit4]   2> 66768 T110 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 66769 T110 oass.SolrIndexSearcher.<init> Opening Searcher@3b47fd[collection1] main
   [junit4]   2> 66770 T111 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3b47fd[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 66770 T110 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 66771 T37 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0
   [junit4]   2> 66771 T114 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:35104 collection:collection1 shard:shard1
   [junit4]   2> 66772 T37 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 66773 T114 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 66780 T114 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 66783 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 66783 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 66783 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 66783 T114 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 66784 T114 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C8 name=collection1 org.apache.solr.core.SolrCore@89c270 url=https://127.0.0.1:35104/collection1 node=127.0.0.1:35104_ C8_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:35104, core=collection1, node_name=127.0.0.1:35104_}
   [junit4]   2> 66784 T114 C8 P35104 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:35104/collection1/
   [junit4]   2> 66785 T114 C8 P35104 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 66785 T70 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 66785 T114 C8 P35104 oasc.SyncStrategy.syncToMe https://127.0.0.1:35104/collection1/ has no replicas
   [junit4]   2> 66786 T114 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:35104/collection1/ shard1
   [junit4]   2> 66786 T114 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 66789 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 66795 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 66803 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 66804 T37 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 66804 T37 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 66809 T37 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 66812 T37 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:49255
   [junit4]   2> 66814 T37 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 66814 T37 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 66814 T37 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1394249364676
   [junit4]   2> 66815 T37 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1394249364676/'
   [junit4]   2> 66831 T37 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1394249364676/solr.xml
   [junit4]   2> 66842 T37 oasc.CoreContainer.<init> New CoreContainer 15245108
   [junit4]   2> 66843 T37 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1394249364676/]
   [junit4]   2> 66846 T37 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 66846 T37 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 66847 T37 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 66847 T37 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 66847 T37 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 66848 T37 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 66848 T37 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 66848 T37 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 66849 T37 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 66853 T37 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 66853 T37 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 66853 T37 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 66854 T37 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46172/solr
   [junit4]   2> 66854 T37 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 66855 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 66857 T125 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d8c0a name:ZooKeeperConnection Watcher:127.0.0.1:46172 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 66857 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 66860 T37 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 66861 T127 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@151cc62 name:ZooKeeperConnection Watcher:127.0.0.1:46172/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 66861 T37 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 66866 T37 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 66907 T78 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 66907 T127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 66907 T69 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 66907 T109 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 66907 T91 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 66947 T114 oasc.ZkController.register We are https://127.0.0.1:35104/collection1/ and leader is https://127.0.0.1:35104/collection1/
   [junit4]   2> 66948 T114 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:35104
   [junit4]   2> 66948 T114 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 66948 T114 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 66948 T114 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 66950 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 66950 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 66950 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 66950 T114 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 66953 T70 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 66955 T70 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:35104",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:35104_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 66958 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 67060 T78 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 67060 T69 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 67060 T91 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 67060 T127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 67060 T109 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 67869 T37 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49255_
   [junit4]   2> 67871 T37 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49255_
   [junit4]   2> 67874 T78 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 67874 T109 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 67874 T91 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 67874 T127 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 67875 T69 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 67881 T128 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 67881 T128 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 67882 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 67883 T128 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 67883 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 67883 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 67885 T70 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 67886 T70 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:49255",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49255_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 67886 T70 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 67886 T70 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 67890 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 67994 T78 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 67994 T69 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 67994 T127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 67994 T109 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 67994 T91 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 68883 T128 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 68884 T128 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1394249364676/collection1
   [junit4]   2> 68884 T128 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 68885 T128 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 68885 T128 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 68886 T128 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 68887 T128 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1394249364676/collection1/'
   [junit4]   2> 68919 T128 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 68937 T128 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 68938 T128 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 68952 T128 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 69094 T128 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 69096 T128 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 69098 T128 oass.IndexSchema.readSchema WARN Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2)
   [junit4]   2> 69098 T128 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (3)
   [junit4]   2> 69100 T128 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 69100 T128 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1394249364676/collection1/, dataDir=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3/
   [junit4]   2> 69101 T128 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 69102 T128 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3
   [junit4]   2> 69102 T128 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3/index/
   [junit4]   2> 69103 T128 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 69104 T128 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3/index
   [junit4]   2> 69106 T128 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/index6063160634tmp lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3/index),segFN=segments_1,generation=1}
   [junit4]   2> 69106 T128 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 69107 T128 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 69108 T128 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 69108 T128 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 69108 T128 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 69108 T128 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 69109 T128 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 69109 T128 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 69110 T128 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
   [junit4]   2> 69111 T128 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 69113 T128 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 69113 T128 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 69114 T128 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/index6063160634tmp lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3/index),segFN=segments_1,generation=1}
   [junit4]   2> 69115 T128 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 69115 T128 oass.SolrIndexSearcher.<init> Opening Searcher@1193295[collection1] main
   [junit4]   2> 69116 T128 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 69117 T37 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0
   [junit4]   2> 69117 T37 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 69117 T132 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:49255 collection:collection1 shard:shard2
   [junit4]   2> 69120 T129 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1193295[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 69123 T132 oasc.ZkController.register We are https://127.0.0.1:49255/collection1/ and leader is https://127.0.0.1:40997/collection1/
   [junit4]   2> 69123 T132 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:49255
   [junit4]   2> 69123 T132 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 69124 T132 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C9 name=collection1 org.apache.solr.core.SolrCore@acb70a url=https://127.0.0.1:49255/collection1 node=127.0.0.1:49255_ C9_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:49255, core=collection1, node_name=127.0.0.1:49255_}
   [junit4]   2> 69130 T133 C9 P49255 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 69130 T132 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 69131 T133 C9 P49255 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 69132 T133 C9 P49255 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
   [junit4]   2> 69133 T133 C9 P49255 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 69138 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 69138 T69 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queu

[...truncated too long message...]

ot talk to ZK
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 85647 T37 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 85648 T127 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
   [junit4]   2> 85648 T146 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
   [junit4]   2> 85649 T127 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@acb70a
   [junit4]   2> 85649 T146 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@de84cd
   [junit4]   2> 85650 T127 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=6,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=2,cumulative_deletesById=1,cumulative_deletesByQuery=2,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=5}
   [junit4]   2> 85650 T146 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=6,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=2,cumulative_deletesById=1,cumulative_deletesByQuery=2,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=5}
   [junit4]   2> 85650 T127 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 85650 T127 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 85651 T127 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 85650 T146 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 85652 T146 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 85652 T146 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 85653 T127 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 85653 T127 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 85653 T127 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3 [CachedDir<<refCount=0;path=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3;done=false>>]
   [junit4]   2> 85654 T146 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 85654 T127 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3
   [junit4]   2> 85654 T146 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 85654 T127 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3/index [CachedDir<<refCount=0;path=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3/index;done=false>>]
   [junit4]   2> 85655 T127 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty3/index
   [junit4]   2> 85654 T146 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty4;done=false>>]
   [junit4]   2> 85655 T127 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 85655 T146 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty4
   [junit4]   2> 85655 T127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 85655 T146 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty4/index;done=false>>]
   [junit4]   2> 85656 T127 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 85656 T146 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1394249357641/jetty4/index
   [junit4]   2> 85656 T127 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 85656 T146 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 85657 T146 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene46: {_version_=PostingsFormat(name=Memory doPackFST= false), multiDefault=PostingsFormat(name=Memory doPackFST= true), a_t=PostingsFormat(name=Memory doPackFST= false), intDefault=PostingsFormat(name=Memory doPackFST= false), range_facet_sl=PostingsFormat(name=Asserting), range_facet_si=PostingsFormat(name=Memory doPackFST= true), id=MockVariableIntBlock(baseBlockSize=76), text=PostingsFormat(name=Asserting), range_facet_l=PostingsFormat(name=Memory doPackFST= false), timestamp=PostingsFormat(name=Memory doPackFST= false)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=es_NI, timezone=Africa/Cairo
   [junit4]   2> NOTE: Linux 3.8.0-36-generic i386/Oracle Corporation 1.8.0 (32-bit)/cpus=8,threads=1,free=12335824,total=51322880
   [junit4]   2> NOTE: All tests run in this JVM: [TestXMLEscaping, TestRetryUtil, TestCoreAdmin, TestUpdateRequestCodec, TestDocumentObjectBinder, ContentStreamTest, CloudSolrServerTest]
   [junit4] Completed on J0 in 81.92s, 2 tests, 1 error <<< FAILURES!

[...truncated 97 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:471: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:451: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:202: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1278: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:911: There were test failures: 49 suites, 281 tests, 1 error

Total time: 52 minutes 58 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-fcs-b132 -client -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure