You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/01/05 19:08:09 UTC
[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 486 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/486/
2 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ShardSplitTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest: 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest:
1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:503)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([2B6E400BDCDB9BD9]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ShardSplitTest
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:503)
at java.util.TimerThread.mainLoop(Timer.java:526)
at java.util.TimerThread.run(Timer.java:505)
at __randomizedtesting.SeedInfo.seed([2B6E400BDCDB9BD9]:0)
Build Log:
[...truncated 11143 lines...]
[junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4] 2> 2832647 T7686 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 2832653 T7686 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ShardSplitTest-1388944892812
[junit4] 2> 2832654 T7686 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2832655 T7687 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2832756 T7686 oasc.ZkTestServer.run start zk server on port:60363
[junit4] 2> 2832757 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2832761 T7694 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b00ae47 name:ZooKeeperConnection Watcher:127.0.0.1:60363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2832761 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2832762 T7686 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2832789 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2832790 T7697 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f2a7f37 name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2832791 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2832791 T7686 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 2832795 T7686 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 2832804 T7686 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 2832806 T7686 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 2832808 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 2832809 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 2832814 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 2832815 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 2832918 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2832919 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2832929 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 2832930 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 2832933 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 2832933 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 2832936 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 2832937 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 2832940 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 2832940 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 2832943 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 2832944 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 2832946 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2832947 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2832950 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 2832950 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 2832953 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 2832954 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 2833239 T7686 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2833244 T7686 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:44202
[junit4] 2> 2833245 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2833245 T7686 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2833246 T7686 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121
[junit4] 2> 2833246 T7686 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/'
[junit4] 2> 2833285 T7686 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/solr.xml
[junit4] 2> 2833378 T7686 oasc.CoreContainer.<init> New CoreContainer 542755691
[junit4] 2> 2833378 T7686 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/]
[junit4] 2> 2833380 T7686 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2833381 T7686 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2833381 T7686 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2833381 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2833382 T7686 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2833382 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2833383 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2833383 T7686 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2833383 T7686 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2833395 T7686 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2833396 T7686 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2833396 T7686 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2833397 T7686 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60363/solr
[junit4] 2> 2833397 T7686 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2833398 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2833401 T7709 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c521c2e name:ZooKeeperConnection Watcher:127.0.0.1:60363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2833402 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2833405 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2833413 T7712 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e8c6f27 name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2833413 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2833416 T7686 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2833427 T7686 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2833429 T7686 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2833432 T7686 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44202_
[junit4] 2> 2833439 T7686 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44202_
[junit4] 2> 2833442 T7686 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2833445 T7686 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2833460 T7686 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2833462 T7686 oasc.Overseer.start Overseer (id=91025892495851523-127.0.0.1:44202_-n_0000000000) starting
[junit4] 2> 2833474 T7686 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2833485 T7714 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2833487 T7686 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2833489 T7686 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2833491 T7686 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2833493 T7713 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2833499 T7715 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 2833499 T7715 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2833501 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2833501 T7715 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2833502 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2833502 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44202",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:44202_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2833503 T7713 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 2833503 T7713 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2833505 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2833514 T7712 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> 2834502 T7715 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2834502 T7715 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/collection1
[junit4] 2> 2834502 T7715 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 2834503 T7715 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2834503 T7715 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2834504 T7715 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/collection1/'
[junit4] 2> 2834506 T7715 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/collection1/lib/README' to classloader
[junit4] 2> 2834507 T7715 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/collection1/lib/classes/' to classloader
[junit4] 2> 2834569 T7715 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 2834630 T7715 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2834732 T7715 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2834742 T7715 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2835300 T7715 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2835305 T7715 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2835307 T7715 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2835312 T7715 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2835332 T7715 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2835332 T7715 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1388944892811/control/data/
[junit4] 2> 2835332 T7715 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6c2bae18
[junit4] 2> 2835333 T7715 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/control/data
[junit4] 2> 2835333 T7715 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1388944892811/control/data/index/
[junit4] 2> 2835334 T7715 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1388944892811/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 2835334 T7715 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/control/data/index
[junit4] 2> 2835335 T7715 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=51.1748046875, floorSegmentMB=1.01953125, forceMergeDeletesPctAllowed=20.22639910826647, segmentsPerTier=17.0, maxCFSSegmentSizeMB=1.361328125, noCFSRatio=1.0
[junit4] 2> 2835336 T7715 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4a1266b2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5c49f02f; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
[junit4] 2> 2835336 T7715 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2835339 T7715 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2835339 T7715 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2835340 T7715 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2835340 T7715 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2835340 T7715 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2835340 T7715 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2835341 T7715 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2835341 T7715 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2835342 T7715 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2835342 T7715 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2835343 T7715 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2835343 T7715 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2835343 T7715 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2835344 T7715 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2835344 T7715 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2835345 T7715 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2835345 T7715 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2835361 T7715 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2835378 T7715 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2835378 T7715 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2835379 T7715 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=16, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5898393679458741]
[junit4] 2> 2835380 T7715 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4a1266b2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5c49f02f; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
[junit4] 2> 2835380 T7715 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2835380 T7715 oass.SolrIndexSearcher.<init> Opening Searcher@5278ff5e main
[junit4] 2> 2835383 T7716 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5278ff5e main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2835385 T7715 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2835386 T7686 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
[junit4] 2> 2835386 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2835386 T7719 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44202 collection:control_collection shard:shard1
[junit4] 2> 2835388 T7719 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 2835388 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2835390 T7722 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11ce6ebf name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2835390 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2835392 T7686 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2835405 T7686 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 2835406 T7719 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2835408 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2835409 T7719 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2835409 T7719 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2589 name=collection1 org.apache.solr.core.SolrCore@15dee390 url=http://127.0.0.1:44202/collection1 node=127.0.0.1:44202_ C2589_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:44202, core=collection1, node_name=127.0.0.1:44202_}
[junit4] 2> 2835409 T7719 C2589 P44202 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44202/collection1/
[junit4] 2> 2835410 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2835410 T7719 C2589 P44202 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2835410 T7719 C2589 P44202 oasc.SyncStrategy.syncToMe http://127.0.0.1:44202/collection1/ has no replicas
[junit4] 2> 2835410 T7719 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44202/collection1/ shard1
[junit4] 2> 2835411 T7719 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 2835413 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2835413 T7712 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> 2835413 T7722 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> 2835418 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2835421 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2835523 T7712 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> 2835523 T7722 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> 2835571 T7719 oasc.ZkController.register We are http://127.0.0.1:44202/collection1/ and leader is http://127.0.0.1:44202/collection1/
[junit4] 2> 2835571 T7719 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44202
[junit4] 2> 2835571 T7719 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2835572 T7719 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 2835572 T7719 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2835613 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2835613 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2835614 T7719 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2835614 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2835615 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2835615 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:44202",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:44202_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 2835682 T7686 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2835685 T7686 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:56357
[junit4] 2> 2835686 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2835687 T7686 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2835687 T7686 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564
[junit4] 2> 2835687 T7686 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/'
[junit4] 2> 2835704 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2835726 T7686 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/solr.xml
[junit4] 2> 2835807 T7712 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> 2835807 T7722 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> 2835818 T7686 oasc.CoreContainer.<init> New CoreContainer 1658576934
[junit4] 2> 2835819 T7686 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/]
[junit4] 2> 2835820 T7686 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2835821 T7686 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2835821 T7686 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2835822 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2835822 T7686 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2835822 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2835823 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2835823 T7686 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2835824 T7686 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2835833 T7686 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2835833 T7686 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2835834 T7686 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2835834 T7686 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60363/solr
[junit4] 2> 2835835 T7686 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2835836 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2835875 T7734 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e8b90eb name:ZooKeeperConnection Watcher:127.0.0.1:60363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2835877 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2835900 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2835902 T7737 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ceeeab4 name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2835902 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2835948 T7686 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2836951 T7686 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56357_
[junit4] 2> 2836953 T7686 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56357_
[junit4] 2> 2836957 T7722 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2836957 T7737 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2836957 T7712 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2836979 T7738 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 2836979 T7738 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2836981 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2836981 T7738 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2836981 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2836981 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2836982 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2836983 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:56357",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56357_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2836983 T7713 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 2836984 T7713 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2836987 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2837090 T7737 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> 2837090 T7722 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> 2837090 T7712 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> 2837982 T7738 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2837982 T7738 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/collection1
[junit4] 2> 2837982 T7738 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2837983 T7738 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2837983 T7738 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2837984 T7738 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/collection1/'
[junit4] 2> 2837985 T7738 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/collection1/lib/README' to classloader
[junit4] 2> 2837986 T7738 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/collection1/lib/classes/' to classloader
[junit4] 2> 2838048 T7738 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 2838109 T7738 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2838210 T7738 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2838219 T7738 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2838764 T7738 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2838767 T7738 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2838769 T7738 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2838772 T7738 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2838790 T7738 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2838791 T7738 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty1/
[junit4] 2> 2838791 T7738 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6c2bae18
[junit4] 2> 2838791 T7738 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty1
[junit4] 2> 2838792 T7738 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty1/index/
[junit4] 2> 2838792 T7738 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 2838793 T7738 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty1/index
[junit4] 2> 2838794 T7738 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=51.1748046875, floorSegmentMB=1.01953125, forceMergeDeletesPctAllowed=20.22639910826647, segmentsPerTier=17.0, maxCFSSegmentSizeMB=1.361328125, noCFSRatio=1.0
[junit4] 2> 2838794 T7738 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@381705c5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d67c554; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
[junit4] 2> 2838795 T7738 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2838797 T7738 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2838797 T7738 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2838798 T7738 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2838798 T7738 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2838798 T7738 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2838798 T7738 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2838799 T7738 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2838799 T7738 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2838799 T7738 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2838800 T7738 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2838800 T7738 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2838800 T7738 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2838800 T7738 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2838801 T7738 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2838801 T7738 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2838801 T7738 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2838802 T7738 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2838812 T7738 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2838816 T7738 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2838816 T7738 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2838817 T7738 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=16, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5898393679458741]
[junit4] 2> 2838817 T7738 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@381705c5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d67c554; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
[junit4] 2> 2838817 T7738 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2838818 T7738 oass.SolrIndexSearcher.<init> Opening Searcher@5a4b96db main
[junit4] 2> 2838820 T7739 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5a4b96db main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2838822 T7738 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2838823 T7686 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
[junit4] 2> 2838824 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2838823 T7742 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56357 collection:collection1 shard:shard1
[junit4] 2> 2838825 T7742 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2838844 T7742 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2838855 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2838855 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2838855 T7742 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2838855 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2838856 T7742 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2590 name=collection1 org.apache.solr.core.SolrCore@6f0b6c21 url=http://127.0.0.1:56357/collection1 node=127.0.0.1:56357_ C2590_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:56357, core=collection1, node_name=127.0.0.1:56357_}
[junit4] 2> 2838856 T7742 C2590 P56357 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56357/collection1/
[junit4] 2> 2838856 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2838856 T7742 C2590 P56357 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2838857 T7742 C2590 P56357 oasc.SyncStrategy.syncToMe http://127.0.0.1:56357/collection1/ has no replicas
[junit4] 2> 2838857 T7742 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56357/collection1/ shard1
[junit4] 2> 2838857 T7742 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2838859 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2838860 T7712 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> 2838860 T7722 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> 2838860 T7737 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> 2838863 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2838864 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2838866 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2838969 T7737 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> 2838969 T7722 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> 2838969 T7712 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> 2839016 T7742 oasc.ZkController.register We are http://127.0.0.1:56357/collection1/ and leader is http://127.0.0.1:56357/collection1/
[junit4] 2> 2839016 T7742 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56357
[junit4] 2> 2839016 T7742 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2839016 T7742 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 2839016 T7742 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2839017 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2839018 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2839018 T7742 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2839018 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2839019 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2839020 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:56357",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56357_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 2839029 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2839096 T7686 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2839099 T7686 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:38382
[junit4] 2> 2839100 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2839100 T7686 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2839101 T7686 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982
[junit4] 2> 2839101 T7686 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/'
[junit4] 2> 2839131 T7737 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> 2839131 T7712 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> 2839131 T7722 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> 2839141 T7686 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/solr.xml
[junit4] 2> 2839233 T7686 oasc.CoreContainer.<init> New CoreContainer 2064723613
[junit4] 2> 2839234 T7686 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/]
[junit4] 2> 2839236 T7686 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2839236 T7686 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2839237 T7686 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2839237 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2839238 T7686 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2839238 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2839238 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2839239 T7686 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2839239 T7686 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2839251 T7686 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2839251 T7686 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2839252 T7686 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2839252 T7686 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60363/solr
[junit4] 2> 2839253 T7686 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2839254 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2839256 T7754 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@172a9306 name:ZooKeeperConnection Watcher:127.0.0.1:60363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2839257 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2839261 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2839267 T7757 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a88a8f6 name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2839268 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2839272 T7686 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2840275 T7686 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38382_
[junit4] 2> 2840277 T7686 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38382_
[junit4] 2> 2840281 T7722 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2840282 T7757 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2840281 T7737 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2840281 T7712 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2840298 T7758 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 2840298 T7758 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2840299 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2840299 T7758 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2840300 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2840300 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2840301 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2840301 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:38382",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:38382_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2840302 T7713 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 2840302 T7713 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2840305 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2840408 T7757 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> 2840408 T7712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2840408 T7722 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> 2840408 T7737 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> 2841301 T7758 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2841301 T7758 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/collection1
[junit4] 2> 2841301 T7758 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2841302 T7758 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2841303 T7758 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2841303 T7758 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/collection1/'
[junit4] 2> 2841305 T7758 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/collection1/lib/README' to classloader
[junit4] 2> 2841306 T7758 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/collection1/lib/classes/' to classloader
[junit4] 2> 2841370 T7758 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 2841442 T7758 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2841543 T7758 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2841553 T7758 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2841996 T7758 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2841999 T7758 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2842000 T7758 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2842004 T7758 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2842018 T7758 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2842018 T7758 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty2/
[junit4] 2> 2842018 T7758 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6c2bae18
[junit4] 2> 2842019 T7758 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty2
[junit4] 2> 2842019 T7758 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty2/index/
[junit4] 2> 2842019 T7758 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 2842020 T7758 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty2/index
[junit4] 2> 2842021 T7758 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=51.1748046875, floorSegmentMB=1.01953125, forceMergeDeletesPctAllowed=20.22639910826647, segmentsPerTier=17.0, maxCFSSegmentSizeMB=1.361328125, noCFSRatio=1.0
[junit4] 2> 2842021 T7758 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4fdd011 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5289967c; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
[junit4] 2> 2842022 T7758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2842024 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2842025 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2842025 T7758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2842025 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2842025 T7758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2842025 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2842026 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2842026 T7758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2842026 T7758 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2842027 T7758 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2842027 T7758 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2842027 T7758 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2842027 T7758 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2842028 T7758 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2842028 T7758 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2842029 T7758 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2842029 T7758 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2842040 T7758 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2842043 T7758 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2842044 T7758 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2842044 T7758 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=16, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5898393679458741]
[junit4] 2> 2842044 T7758 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4fdd011 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5289967c; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
[junit4] 2> 2842045 T7758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2842045 T7758 oass.SolrIndexSearcher.<init> Opening Searcher@2f5b1603 main
[junit4] 2> 2842047 T7759 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2f5b1603 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2842049 T7758 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2842049 T7686 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
[junit4] 2> 2842050 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2842049 T7762 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38382 collection:collection1 shard:shard2
[junit4] 2> 2842051 T7762 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2842067 T7762 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 2842069 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2842069 T7762 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2842069 T7762 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 2842069 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> ASYNC NEW_CORE C2591 name=collection1 org.apache.solr.core.SolrCore@3327f008 url=http://127.0.0.1:38382/collection1 node=127.0.0.1:38382_ C2591_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:38382, core=collection1, node_name=127.0.0.1:38382_}
[junit4] 2> 2842069 T7762 C2591 P38382 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38382/collection1/
[junit4] 2> 2842070 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2842070 T7762 C2591 P38382 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2842070 T7762 C2591 P38382 oasc.SyncStrategy.syncToMe http://127.0.0.1:38382/collection1/ has no replicas
[junit4] 2> 2842070 T7762 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38382/collection1/ shard2
[junit4] 2> 2842070 T7762 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2842071 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2842074 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2842075 T7757 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> 2842075 T7737 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> 2842075 T7722 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> 2842075 T7712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2842077 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2842080 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2842183 T7757 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> 2842183 T7722 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> 2842183 T7737 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> 2842183 T7712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2842228 T7762 oasc.ZkController.register We are http://127.0.0.1:38382/collection1/ and leader is http://127.0.0.1:38382/collection1/
[junit4] 2> 2842228 T7762 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38382
[junit4] 2> 2842228 T7762 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2842228 T7762 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 2842228 T7762 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2842230 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2842230 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2842230 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2842230 T7762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2842231 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2842231 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:38382",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:38382_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 2842232 T7686 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2842234 T7686 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:45611
[junit4] 2> 2842234 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2842235 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2842235 T7686 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2842235 T7686 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208
[junit4] 2> 2842236 T7686 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/'
[junit4] 2> 2842262 T7686 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/solr.xml
[junit4] 2> 2842323 T7686 oasc.CoreContainer.<init> New CoreContainer 1245378889
[junit4] 2> 2842323 T7686 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/]
[junit4] 2> 2842324 T7686 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2842325 T7686 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2842325 T7686 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2842325 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2842326 T7686 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2842326 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2842326 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2842326 T7686 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2842327 T7686 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2842334 T7686 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2842335 T7686 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2842335 T7686 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2842335 T7686 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60363/solr
[junit4] 2> 2842336 T7686 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2842336 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2842338 T7757 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> 2842338 T7722 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> 2842338 T7737 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> 2842338 T7712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2842340 T7774 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56c01a65 name:ZooKeeperConnection Watcher:127.0.0.1:60363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2842340 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2842351 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2842353 T7777 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23b0b33d name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2842354 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2842363 T7686 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2843366 T7686 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45611_
[junit4] 2> 2843394 T7686 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45611_
[junit4] 2> 2843397 T7777 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2843398 T7737 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2843398 T7712 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2843398 T7757 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2843397 T7722 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2843415 T7778 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 2843415 T7778 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2843416 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2843416 T7778 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2843417 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2843417 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2843418 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2843418 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45611",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45611_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2843418 T7713 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 2843419 T7713 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2843422 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2843524 T7722 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> 2843524 T7737 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> 2843524 T7757 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> 2843524 T7777 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> 2843524 T7712 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> 2844418 T7778 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2844418 T7778 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/collection1
[junit4] 2> 2844418 T7778 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2844419 T7778 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2844419 T7778 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2844420 T7778 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/collection1/'
[junit4] 2> 2844421 T7778 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/collection1/lib/classes/' to classloader
[junit4] 2> 2844422 T7778 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/collection1/lib/README' to classloader
[junit4] 2> 2844466 T7778 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 2844508 T7778 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2844610 T7778 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2844617 T7778 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2845020 T7778 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2845023 T7778 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2845025 T7778 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2845028 T7778 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2845043 T7778 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2845043 T7778 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty3/
[junit4] 2> 2845043 T7778 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6c2bae18
[junit4] 2> 2845044 T7778 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty3
[junit4] 2> 2845044 T7778 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty3/index/
[junit4] 2> 2845044 T7778 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 2845046 T7778 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty3/index
[junit4] 2> 2845046 T7778 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=51.1748046875, floorSegmentMB=1.01953125, forceMergeDeletesPctAllowed=20.22639910826647, segmentsPerTier=17.0, maxCFSSegmentSizeMB=1.361328125, noCFSRatio=1.0
[junit4] 2> 2845047 T7778 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@69634371 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e64b14d; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
[junit4] 2> 2845047 T7778 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2845050 T7778 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2845050 T7778 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2845050 T7778 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2845051 T7778 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2845051 T7778 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_s
[...truncated too long message...]
a:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 3169708 T7798 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:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[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:138)
[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> 337466 T7685 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> 357525 T7685 ccr.ThreadLeakControl.checkThreadLeaks SEVERE 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest:
[junit4] 2> 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:503)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> 357526 T7685 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
[junit4] 2> 360533 T7685 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:503)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=pl_PL, timezone=Africa/Sao_Tome
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=2,free=279178864,total=494141440
[junit4] 2> NOTE: All tests run in this JVM: [TestUniqueKeyFieldResource, RAMDirectoryFactoryTest, DistributedSuggestComponentTest, TestComponentsName, BasicZkTest, ShardRoutingCustomTest, CollectionsAPIDistributedZkTest, SpellingQueryConverterTest, DirectSolrConnectionTest, TestNumberUtils, SolrCmdDistributorTest, TestAnalyzedSuggestions, TestAddFieldRealTimeGet, TestSolrQueryParserDefaultOperatorResource, HighlighterTest, ChangedSchemaMergeTest, TestUpdate, RequiredFieldsTest, BlockDirectoryTest, SimplePostToolTest, TestRangeQuery, TestSolrDeletionPolicy2, AlternateDirectoryTest, TestIndexSearcher, IndexBasedSpellCheckerTest, AliasIntegrationTest, TestBinaryResponseWriter, AddBlockUpdateTest, TestClassNameShortening, TestFastLRUCache, DateFieldTest, TestStressReorder, OutputWriterTest, TestFoldingMultitermQuery, MinimalSchemaTest, TestCoreDiscovery, TestHashPartitioner, TestFieldTypeCollectionResource, TestOmitPositions, TestSolrQueryParserResource, ZkSolrClientTest, TestRTGBase, RequestHandlersTest, TestNRTOpen, StatsComponentTest, TimeZoneUtilsTest, BlockCacheTest, ConnectionManagerTest, TestAtomicUpdateErrorCases, TestSolrXmlPersistence, TestArbitraryIndexDir, StressHdfsTest, TestSweetSpotSimilarityFactory, TestBinaryField, TestStressRecovery, SolrPluginUtilsTest, TestZkChroot, SpellCheckCollatorTest, TestCSVLoader, DebugComponentTest, TestSolr4Spatial, TestDFRSimilarityFactory, XsltUpdateRequestHandlerTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestIBSimilarityFactory, OpenExchangeRatesOrgProviderTest, ChaosMonkeySafeLeaderTest, TestIndexingPerformance, TestCodecSupport, FieldAnalysisRequestHandlerTest, UniqFieldsUpdateProcessorFactoryTest, DocValuesMultiTest, TestSolrJ, TestQuerySenderListener, DistributedQueryComponentCustomSortTest, TestRandomMergePolicy, FieldFacetExtrasTest, DefaultValueUpdateProcessorTest, TestPhraseSuggestions, IndexSchemaRuntimeFieldTest, CachingDirectoryFactoryTest, TestDistribDocBasedVersion, StandardRequestHandlerTest, AbstractAnalyticsStatsTest, TestFastWriter, QueryFacetTest, TestFieldResource, BadIndexSchemaTest, BasicDistributedZk2Test, SyncSliceTest, LeaderElectionIntegrationTest, ClusterStateUpdateTest, TestRandomFaceting, TestDistributedGrouping, TestFaceting, TestRecovery, TermVectorComponentDistributedTest, ZkControllerTest, TestRealTimeGet, TestJoin, TestMultiCoreConfBootstrap, TestReload, TestCoreContainer, TestGroupingSearch, DirectUpdateHandlerTest, OverseerCollectionProcessorTest, CurrencyFieldOpenExchangeTest, SolrIndexSplitterTest, AnalysisAfterCoreReloadTest, SolrRequestParserTest, TestStressLucene, PolyFieldTest, SolrCoreCheckLockOnStartupTest, TestWordDelimiterFilterFactory, SortByFunctionTest, TestSolrDeletionPolicy1, LukeRequestHandlerTest, DirectSolrSpellCheckerTest, TestQueryTypes, TermsComponentTest, TestValueSourceCache, FastVectorHighlighterTest, TestJmxIntegration, TestCSVResponseWriter, JsonLoaderTest, TestPHPSerializedResponseWriter, SearchHandlerTest, HighlighterConfigTest, UpdateParamsTest, TestQuerySenderNoQuery, ResponseLogComponentTest, BadComponentTest, TestSearchPerf, TestFuzzyAnalyzedSuggestions, TestSolrCoreProperties, NotRequiredUniqueKeyTest, TestLuceneMatchVersion, TestPerFieldSimilarity, TestDefaultSimilarityFactory, TestFastOutputStream, URLClassifyProcessorTest, PreAnalyzedFieldTest, PrimUtilsTest, TestUtils, TestDocumentBuilder, ZkNodePropsTest, SystemInfoHandlerTest, FileUtilsTest, SolrTestCaseJ4Test, TestDistributedMissingSort, ExpressionTest, AbstractAnalyticsFacetTest, FieldFacetTest, FunctionTest, AssignTest, DeleteReplicaTest, DeleteShardTest, MigrateRouteKeyTest, ShardSplitTest]
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ShardSplitTest -Dtests.seed=2B6E400BDCDB9BD9 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=pl_PL -Dtests.timezone=Africa/Sao_Tome -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J1 | ShardSplitTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest:
[junit4] > 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
[junit4] > at java.lang.Object.wait(Native Method)
[junit4] > at java.lang.Object.wait(Object.java:503)
[junit4] > at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] > at java.util.TimerThread.run(Timer.java:505)
[junit4] > at __randomizedtesting.SeedInfo.seed([2B6E400BDCDB9BD9]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
[junit4] > at java.lang.Object.wait(Native Method)
[junit4] > at java.lang.Object.wait(Object.java:503)
[junit4] > at java.util.TimerThread.mainLoop(Timer.java:526)
[junit4] > at java.util.TimerThread.run(Timer.java:505)
[junit4] > at __randomizedtesting.SeedInfo.seed([2B6E400BDCDB9BD9]:0)
[junit4] Completed on J1 in 360.59s, 1 test, 2 errors <<< FAILURES!
[...truncated 13 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:460: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:433: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1304: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:937: There were test failures: 358 suites, 1577 tests, 2 suite-level errors, 33 ignored (4 assumptions)
Total time: 116 minutes 37 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
Re: [JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 486 - Still Failing
Posted by Mark Miller <ma...@gmail.com>.
Just tried again on this one.
- Mark
On Jan 5, 2014, at 1:08 PM, Apache Jenkins Server <je...@builds.apache.org> wrote:
> Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/486/
>
> 2 tests failed.
> FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ShardSplitTest
>
> Error Message:
> 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest: 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
>
> Stack Trace:
> com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest:
> 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
> at java.lang.Object.wait(Native Method)
> at java.lang.Object.wait(Object.java:503)
> at java.util.TimerThread.mainLoop(Timer.java:526)
> at java.util.TimerThread.run(Timer.java:505)
> at __randomizedtesting.SeedInfo.seed([2B6E400BDCDB9BD9]:0)
>
>
> FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ShardSplitTest
>
> Error Message:
> There are still zombie threads that couldn't be terminated: 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) at java.util.TimerThread.run(Timer.java:505)
>
> Stack Trace:
> com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
> 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
> at java.lang.Object.wait(Native Method)
> at java.lang.Object.wait(Object.java:503)
> at java.util.TimerThread.mainLoop(Timer.java:526)
> at java.util.TimerThread.run(Timer.java:505)
> at __randomizedtesting.SeedInfo.seed([2B6E400BDCDB9BD9]:0)
>
>
>
>
> Build Log:
> [...truncated 11143 lines...]
> [junit4] Suite: org.apache.solr.cloud.ShardSplitTest
> [junit4] 2> 2832647 T7686 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
> [junit4] 2> 2832653 T7686 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
> [junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ShardSplitTest-1388944892812
> [junit4] 2> 2832654 T7686 oasc.ZkTestServer.run STARTING ZK TEST SERVER
> [junit4] 2> 2832655 T7687 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
> [junit4] 2> 2832756 T7686 oasc.ZkTestServer.run start zk server on port:60363
> [junit4] 2> 2832757 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 2832761 T7694 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b00ae47 name:ZooKeeperConnection Watcher:127.0.0.1:60363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 2832761 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 2832762 T7686 oascc.SolrZkClient.makePath makePath: /solr
> [junit4] 2> 2832789 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 2832790 T7697 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f2a7f37 name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 2832791 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 2832791 T7686 oascc.SolrZkClient.makePath makePath: /collections/collection1
> [junit4] 2> 2832795 T7686 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
> [junit4] 2> 2832804 T7686 oascc.SolrZkClient.makePath makePath: /collections/control_collection
> [junit4] 2> 2832806 T7686 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
> [junit4] 2> 2832808 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
> [junit4] 2> 2832809 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
> [junit4] 2> 2832814 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
> [junit4] 2> 2832815 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
> [junit4] 2> 2832918 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
> [junit4] 2> 2832919 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
> [junit4] 2> 2832929 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
> [junit4] 2> 2832930 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
> [junit4] 2> 2832933 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
> [junit4] 2> 2832933 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
> [junit4] 2> 2832936 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
> [junit4] 2> 2832937 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
> [junit4] 2> 2832940 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
> [junit4] 2> 2832940 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
> [junit4] 2> 2832943 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
> [junit4] 2> 2832944 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
> [junit4] 2> 2832946 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
> [junit4] 2> 2832947 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
> [junit4] 2> 2832950 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
> [junit4] 2> 2832950 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
> [junit4] 2> 2832953 T7686 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
> [junit4] 2> 2832954 T7686 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
> [junit4] 2> 2833239 T7686 oejs.Server.doStart jetty-8.1.10.v20130312
> [junit4] 2> 2833244 T7686 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:44202
> [junit4] 2> 2833245 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
> [junit4] 2> 2833245 T7686 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
> [junit4] 2> 2833246 T7686 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121
> [junit4] 2> 2833246 T7686 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/'
> [junit4] 2> 2833285 T7686 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/solr.xml
> [junit4] 2> 2833378 T7686 oasc.CoreContainer.<init> New CoreContainer 542755691
> [junit4] 2> 2833378 T7686 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/]
> [junit4] 2> 2833380 T7686 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
> [junit4] 2> 2833381 T7686 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
> [junit4] 2> 2833381 T7686 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
> [junit4] 2> 2833381 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
> [junit4] 2> 2833382 T7686 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
> [junit4] 2> 2833382 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
> [junit4] 2> 2833383 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
> [junit4] 2> 2833383 T7686 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
> [junit4] 2> 2833383 T7686 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
> [junit4] 2> 2833395 T7686 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
> [junit4] 2> 2833396 T7686 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
> [junit4] 2> 2833396 T7686 oasc.CoreContainer.load Host Name: 127.0.0.1
> [junit4] 2> 2833397 T7686 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60363/solr
> [junit4] 2> 2833397 T7686 oasc.ZkController.checkChrootPath zkHost includes chroot
> [junit4] 2> 2833398 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 2833401 T7709 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c521c2e name:ZooKeeperConnection Watcher:127.0.0.1:60363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 2833402 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 2833405 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 2833413 T7712 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e8c6f27 name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 2833413 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 2833416 T7686 oascc.SolrZkClient.makePath makePath: /overseer/queue
> [junit4] 2> 2833427 T7686 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
> [junit4] 2> 2833429 T7686 oascc.SolrZkClient.makePath makePath: /live_nodes
> [junit4] 2> 2833432 T7686 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44202_
> [junit4] 2> 2833439 T7686 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44202_
> [junit4] 2> 2833442 T7686 oascc.SolrZkClient.makePath makePath: /overseer_elect
> [junit4] 2> 2833445 T7686 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
> [junit4] 2> 2833460 T7686 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
> [junit4] 2> 2833462 T7686 oasc.Overseer.start Overseer (id=91025892495851523-127.0.0.1:44202_-n_0000000000) starting
> [junit4] 2> 2833474 T7686 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
> [junit4] 2> 2833485 T7714 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
> [junit4] 2> 2833487 T7686 oascc.SolrZkClient.makePath makePath: /clusterstate.json
> [junit4] 2> 2833489 T7686 oascc.SolrZkClient.makePath makePath: /aliases.json
> [junit4] 2> 2833491 T7686 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
> [junit4] 2> 2833493 T7713 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
> [junit4] 2> 2833499 T7715 oasc.ZkController.publish publishing core=collection1 state=down
> [junit4] 2> 2833499 T7715 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
> [junit4] 2> 2833501 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2833501 T7715 oasc.ZkController.waitForCoreNodeName look for our core node name
> [junit4] 2> 2833502 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2833502 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
> [junit4] 2> "operation":"state",
> [junit4] 2> "state":"down",
> [junit4] 2> "base_url":"http://127.0.0.1:44202",
> [junit4] 2> "core":"collection1",
> [junit4] 2> "roles":null,
> [junit4] 2> "node_name":"127.0.0.1:44202_",
> [junit4] 2> "shard":null,
> [junit4] 2> "shard_range":null,
> [junit4] 2> "shard_state":"active",
> [junit4] 2> "shard_parent":null,
> [junit4] 2> "collection":"control_collection",
> [junit4] 2> "numShards":"1",
> [junit4] 2> "core_node_name":null}
> [junit4] 2> 2833503 T7713 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
> [junit4] 2> 2833503 T7713 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
> [junit4] 2> 2833505 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2833514 T7712 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> 2834502 T7715 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
> [junit4] 2> 2834502 T7715 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/collection1
> [junit4] 2> 2834502 T7715 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
> [junit4] 2> 2834503 T7715 oasc.ZkController.createCollectionZkNode Collection zkNode exists
> [junit4] 2> 2834503 T7715 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
> [junit4] 2> 2834504 T7715 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/collection1/'
> [junit4] 2> 2834506 T7715 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/collection1/lib/README' to classloader
> [junit4] 2> 2834507 T7715 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/collection1/lib/classes/' to classloader
> [junit4] 2> 2834569 T7715 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
> [junit4] 2> 2834630 T7715 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
> [junit4] 2> 2834732 T7715 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
> [junit4] 2> 2834742 T7715 oass.IndexSchema.readSchema [collection1] Schema name=test
> [junit4] 2> 2835300 T7715 oass.IndexSchema.readSchema default search field in schema is text
> [junit4] 2> 2835305 T7715 oass.IndexSchema.readSchema unique key field: id
> [junit4] 2> 2835307 T7715 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 2835312 T7715 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 2835332 T7715 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
> [junit4] 2> 2835332 T7715 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1388944893121/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1388944892811/control/data/
> [junit4] 2> 2835332 T7715 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6c2bae18
> [junit4] 2> 2835333 T7715 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/control/data
> [junit4] 2> 2835333 T7715 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1388944892811/control/data/index/
> [junit4] 2> 2835334 T7715 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1388944892811/control/data/index' doesn't exist. Creating new index...
> [junit4] 2> 2835334 T7715 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/control/data/index
> [junit4] 2> 2835335 T7715 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=51.1748046875, floorSegmentMB=1.01953125, forceMergeDeletesPctAllowed=20.22639910826647, segmentsPerTier=17.0, maxCFSSegmentSizeMB=1.361328125, noCFSRatio=1.0
> [junit4] 2> 2835336 T7715 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4a1266b2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5c49f02f; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
> [junit4] 2> 2835336 T7715 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 2835339 T7715 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
> [junit4] 2> 2835339 T7715 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
> [junit4] 2> 2835340 T7715 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
> [junit4] 2> 2835340 T7715 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
> [junit4] 2> 2835340 T7715 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
> [junit4] 2> 2835340 T7715 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
> [junit4] 2> 2835341 T7715 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 2835341 T7715 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 2835342 T7715 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
> [junit4] 2> 2835342 T7715 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
> [junit4] 2> 2835343 T7715 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
> [junit4] 2> 2835343 T7715 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
> [junit4] 2> 2835343 T7715 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
> [junit4] 2> 2835344 T7715 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
> [junit4] 2> 2835344 T7715 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
> [junit4] 2> 2835345 T7715 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
> [junit4] 2> 2835345 T7715 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
> [junit4] 2> 2835361 T7715 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
> [junit4] 2> 2835378 T7715 oasu.CommitTracker.<init> Hard AutoCommit: disabled
> [junit4] 2> 2835378 T7715 oasu.CommitTracker.<init> Soft AutoCommit: disabled
> [junit4] 2> 2835379 T7715 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=16, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5898393679458741]
> [junit4] 2> 2835380 T7715 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4a1266b2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5c49f02f; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
> [junit4] 2> 2835380 T7715 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 2835380 T7715 oass.SolrIndexSearcher.<init> Opening Searcher@5278ff5e main
> [junit4] 2> 2835383 T7716 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5278ff5e main{StandardDirectoryReader(segments_1:1:nrt)}
> [junit4] 2> 2835385 T7715 oasc.CoreContainer.registerCore registering core: collection1
> [junit4] 2> 2835386 T7686 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
> [junit4] 2> 2835386 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
> [junit4] 2> 2835386 T7719 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44202 collection:control_collection shard:shard1
> [junit4] 2> 2835388 T7719 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
> [junit4] 2> 2835388 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 2835390 T7722 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11ce6ebf name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 2835390 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 2835392 T7686 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
> [junit4] 2> 2835405 T7686 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
> [junit4] 2> 2835406 T7719 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
> [junit4] 2> 2835408 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2835409 T7719 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
> [junit4] 2> 2835409 T7719 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
> [junit4] 2> ASYNC NEW_CORE C2589 name=collection1 org.apache.solr.core.SolrCore@15dee390 url=http://127.0.0.1:44202/collection1 node=127.0.0.1:44202_ C2589_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:44202, core=collection1, node_name=127.0.0.1:44202_}
> [junit4] 2> 2835409 T7719 C2589 P44202 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44202/collection1/
> [junit4] 2> 2835410 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2835410 T7719 C2589 P44202 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
> [junit4] 2> 2835410 T7719 C2589 P44202 oasc.SyncStrategy.syncToMe http://127.0.0.1:44202/collection1/ has no replicas
> [junit4] 2> 2835410 T7719 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44202/collection1/ shard1
> [junit4] 2> 2835411 T7719 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
> [junit4] 2> 2835413 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2835413 T7712 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> 2835413 T7722 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> 2835418 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2835421 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2835523 T7712 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> 2835523 T7722 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> 2835571 T7719 oasc.ZkController.register We are http://127.0.0.1:44202/collection1/ and leader is http://127.0.0.1:44202/collection1/
> [junit4] 2> 2835571 T7719 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44202
> [junit4] 2> 2835571 T7719 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
> [junit4] 2> 2835572 T7719 oasc.ZkController.publish publishing core=collection1 state=active
> [junit4] 2> 2835572 T7719 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
> [junit4] 2> 2835613 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2835613 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2835614 T7719 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2835614 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2835615 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2835615 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
> [junit4] 2> "operation":"state",
> [junit4] 2> "state":"active",
> [junit4] 2> "base_url":"http://127.0.0.1:44202",
> [junit4] 2> "core":"collection1",
> [junit4] 2> "roles":null,
> [junit4] 2> "node_name":"127.0.0.1:44202_",
> [junit4] 2> "shard":"shard1",
> [junit4] 2> "shard_range":null,
> [junit4] 2> "shard_state":"active",
> [junit4] 2> "shard_parent":null,
> [junit4] 2> "collection":"control_collection",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "core_node_name":"core_node1"}
> [junit4] 2> 2835682 T7686 oejs.Server.doStart jetty-8.1.10.v20130312
> [junit4] 2> 2835685 T7686 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:56357
> [junit4] 2> 2835686 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
> [junit4] 2> 2835687 T7686 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
> [junit4] 2> 2835687 T7686 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564
> [junit4] 2> 2835687 T7686 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/'
> [junit4] 2> 2835704 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2835726 T7686 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/solr.xml
> [junit4] 2> 2835807 T7712 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> 2835807 T7722 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> 2835818 T7686 oasc.CoreContainer.<init> New CoreContainer 1658576934
> [junit4] 2> 2835819 T7686 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/]
> [junit4] 2> 2835820 T7686 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
> [junit4] 2> 2835821 T7686 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
> [junit4] 2> 2835821 T7686 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
> [junit4] 2> 2835822 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
> [junit4] 2> 2835822 T7686 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
> [junit4] 2> 2835822 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
> [junit4] 2> 2835823 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
> [junit4] 2> 2835823 T7686 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
> [junit4] 2> 2835824 T7686 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
> [junit4] 2> 2835833 T7686 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
> [junit4] 2> 2835833 T7686 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
> [junit4] 2> 2835834 T7686 oasc.CoreContainer.load Host Name: 127.0.0.1
> [junit4] 2> 2835834 T7686 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60363/solr
> [junit4] 2> 2835835 T7686 oasc.ZkController.checkChrootPath zkHost includes chroot
> [junit4] 2> 2835836 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 2835875 T7734 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e8b90eb name:ZooKeeperConnection Watcher:127.0.0.1:60363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 2835877 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 2835900 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 2835902 T7737 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ceeeab4 name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 2835902 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 2835948 T7686 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
> [junit4] 2> 2836951 T7686 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56357_
> [junit4] 2> 2836953 T7686 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56357_
> [junit4] 2> 2836957 T7722 oascc.ZkStateReader$3.process Updating live nodes... (2)
> [junit4] 2> 2836957 T7737 oascc.ZkStateReader$3.process Updating live nodes... (2)
> [junit4] 2> 2836957 T7712 oascc.ZkStateReader$3.process Updating live nodes... (2)
> [junit4] 2> 2836979 T7738 oasc.ZkController.publish publishing core=collection1 state=down
> [junit4] 2> 2836979 T7738 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
> [junit4] 2> 2836981 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2836981 T7738 oasc.ZkController.waitForCoreNodeName look for our core node name
> [junit4] 2> 2836981 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2836981 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2836982 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2836983 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
> [junit4] 2> "operation":"state",
> [junit4] 2> "state":"down",
> [junit4] 2> "base_url":"http://127.0.0.1:56357",
> [junit4] 2> "core":"collection1",
> [junit4] 2> "roles":null,
> [junit4] 2> "node_name":"127.0.0.1:56357_",
> [junit4] 2> "shard":null,
> [junit4] 2> "shard_range":null,
> [junit4] 2> "shard_state":"active",
> [junit4] 2> "shard_parent":null,
> [junit4] 2> "collection":"collection1",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "core_node_name":null}
> [junit4] 2> 2836983 T7713 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
> [junit4] 2> 2836984 T7713 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
> [junit4] 2> 2836987 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2837090 T7737 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> 2837090 T7722 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> 2837090 T7712 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> 2837982 T7738 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
> [junit4] 2> 2837982 T7738 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/collection1
> [junit4] 2> 2837982 T7738 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
> [junit4] 2> 2837983 T7738 oasc.ZkController.createCollectionZkNode Collection zkNode exists
> [junit4] 2> 2837983 T7738 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
> [junit4] 2> 2837984 T7738 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/collection1/'
> [junit4] 2> 2837985 T7738 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/collection1/lib/README' to classloader
> [junit4] 2> 2837986 T7738 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/collection1/lib/classes/' to classloader
> [junit4] 2> 2838048 T7738 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
> [junit4] 2> 2838109 T7738 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
> [junit4] 2> 2838210 T7738 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
> [junit4] 2> 2838219 T7738 oass.IndexSchema.readSchema [collection1] Schema name=test
> [junit4] 2> 2838764 T7738 oass.IndexSchema.readSchema default search field in schema is text
> [junit4] 2> 2838767 T7738 oass.IndexSchema.readSchema unique key field: id
> [junit4] 2> 2838769 T7738 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 2838772 T7738 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 2838790 T7738 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
> [junit4] 2> 2838791 T7738 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty1-1388944895564/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty1/
> [junit4] 2> 2838791 T7738 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6c2bae18
> [junit4] 2> 2838791 T7738 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty1
> [junit4] 2> 2838792 T7738 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty1/index/
> [junit4] 2> 2838792 T7738 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty1/index' doesn't exist. Creating new index...
> [junit4] 2> 2838793 T7738 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty1/index
> [junit4] 2> 2838794 T7738 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=51.1748046875, floorSegmentMB=1.01953125, forceMergeDeletesPctAllowed=20.22639910826647, segmentsPerTier=17.0, maxCFSSegmentSizeMB=1.361328125, noCFSRatio=1.0
> [junit4] 2> 2838794 T7738 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@381705c5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d67c554; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
> [junit4] 2> 2838795 T7738 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 2838797 T7738 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
> [junit4] 2> 2838797 T7738 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
> [junit4] 2> 2838798 T7738 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
> [junit4] 2> 2838798 T7738 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
> [junit4] 2> 2838798 T7738 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
> [junit4] 2> 2838798 T7738 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
> [junit4] 2> 2838799 T7738 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 2838799 T7738 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 2838799 T7738 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
> [junit4] 2> 2838800 T7738 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
> [junit4] 2> 2838800 T7738 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
> [junit4] 2> 2838800 T7738 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
> [junit4] 2> 2838800 T7738 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
> [junit4] 2> 2838801 T7738 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
> [junit4] 2> 2838801 T7738 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
> [junit4] 2> 2838801 T7738 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
> [junit4] 2> 2838802 T7738 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
> [junit4] 2> 2838812 T7738 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
> [junit4] 2> 2838816 T7738 oasu.CommitTracker.<init> Hard AutoCommit: disabled
> [junit4] 2> 2838816 T7738 oasu.CommitTracker.<init> Soft AutoCommit: disabled
> [junit4] 2> 2838817 T7738 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=16, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5898393679458741]
> [junit4] 2> 2838817 T7738 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@381705c5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d67c554; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
> [junit4] 2> 2838817 T7738 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 2838818 T7738 oass.SolrIndexSearcher.<init> Opening Searcher@5a4b96db main
> [junit4] 2> 2838820 T7739 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5a4b96db main{StandardDirectoryReader(segments_1:1:nrt)}
> [junit4] 2> 2838822 T7738 oasc.CoreContainer.registerCore registering core: collection1
> [junit4] 2> 2838823 T7686 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
> [junit4] 2> 2838824 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
> [junit4] 2> 2838823 T7742 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56357 collection:collection1 shard:shard1
> [junit4] 2> 2838825 T7742 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
> [junit4] 2> 2838844 T7742 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
> [junit4] 2> 2838855 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2838855 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2838855 T7742 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
> [junit4] 2> 2838855 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2838856 T7742 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
> [junit4] 2> ASYNC NEW_CORE C2590 name=collection1 org.apache.solr.core.SolrCore@6f0b6c21 url=http://127.0.0.1:56357/collection1 node=127.0.0.1:56357_ C2590_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:56357, core=collection1, node_name=127.0.0.1:56357_}
> [junit4] 2> 2838856 T7742 C2590 P56357 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56357/collection1/
> [junit4] 2> 2838856 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2838856 T7742 C2590 P56357 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
> [junit4] 2> 2838857 T7742 C2590 P56357 oasc.SyncStrategy.syncToMe http://127.0.0.1:56357/collection1/ has no replicas
> [junit4] 2> 2838857 T7742 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56357/collection1/ shard1
> [junit4] 2> 2838857 T7742 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
> [junit4] 2> 2838859 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2838860 T7712 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> 2838860 T7722 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> 2838860 T7737 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> 2838863 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2838864 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2838866 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2838969 T7737 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> 2838969 T7722 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> 2838969 T7712 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> 2839016 T7742 oasc.ZkController.register We are http://127.0.0.1:56357/collection1/ and leader is http://127.0.0.1:56357/collection1/
> [junit4] 2> 2839016 T7742 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56357
> [junit4] 2> 2839016 T7742 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
> [junit4] 2> 2839016 T7742 oasc.ZkController.publish publishing core=collection1 state=active
> [junit4] 2> 2839016 T7742 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
> [junit4] 2> 2839017 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2839018 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2839018 T7742 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2839018 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2839019 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2839020 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
> [junit4] 2> "operation":"state",
> [junit4] 2> "state":"active",
> [junit4] 2> "base_url":"http://127.0.0.1:56357",
> [junit4] 2> "core":"collection1",
> [junit4] 2> "roles":null,
> [junit4] 2> "node_name":"127.0.0.1:56357_",
> [junit4] 2> "shard":"shard1",
> [junit4] 2> "shard_range":null,
> [junit4] 2> "shard_state":"active",
> [junit4] 2> "shard_parent":null,
> [junit4] 2> "collection":"collection1",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "core_node_name":"core_node1"}
> [junit4] 2> 2839029 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2839096 T7686 oejs.Server.doStart jetty-8.1.10.v20130312
> [junit4] 2> 2839099 T7686 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:38382
> [junit4] 2> 2839100 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
> [junit4] 2> 2839100 T7686 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
> [junit4] 2> 2839101 T7686 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982
> [junit4] 2> 2839101 T7686 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/'
> [junit4] 2> 2839131 T7737 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> 2839131 T7712 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> 2839131 T7722 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> 2839141 T7686 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/solr.xml
> [junit4] 2> 2839233 T7686 oasc.CoreContainer.<init> New CoreContainer 2064723613
> [junit4] 2> 2839234 T7686 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/]
> [junit4] 2> 2839236 T7686 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
> [junit4] 2> 2839236 T7686 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
> [junit4] 2> 2839237 T7686 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
> [junit4] 2> 2839237 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
> [junit4] 2> 2839238 T7686 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
> [junit4] 2> 2839238 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
> [junit4] 2> 2839238 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
> [junit4] 2> 2839239 T7686 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
> [junit4] 2> 2839239 T7686 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
> [junit4] 2> 2839251 T7686 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
> [junit4] 2> 2839251 T7686 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
> [junit4] 2> 2839252 T7686 oasc.CoreContainer.load Host Name: 127.0.0.1
> [junit4] 2> 2839252 T7686 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60363/solr
> [junit4] 2> 2839253 T7686 oasc.ZkController.checkChrootPath zkHost includes chroot
> [junit4] 2> 2839254 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 2839256 T7754 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@172a9306 name:ZooKeeperConnection Watcher:127.0.0.1:60363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 2839257 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 2839261 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 2839267 T7757 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a88a8f6 name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 2839268 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 2839272 T7686 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
> [junit4] 2> 2840275 T7686 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38382_
> [junit4] 2> 2840277 T7686 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38382_
> [junit4] 2> 2840281 T7722 oascc.ZkStateReader$3.process Updating live nodes... (3)
> [junit4] 2> 2840282 T7757 oascc.ZkStateReader$3.process Updating live nodes... (3)
> [junit4] 2> 2840281 T7737 oascc.ZkStateReader$3.process Updating live nodes... (3)
> [junit4] 2> 2840281 T7712 oascc.ZkStateReader$3.process Updating live nodes... (3)
> [junit4] 2> 2840298 T7758 oasc.ZkController.publish publishing core=collection1 state=down
> [junit4] 2> 2840298 T7758 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
> [junit4] 2> 2840299 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2840299 T7758 oasc.ZkController.waitForCoreNodeName look for our core node name
> [junit4] 2> 2840300 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2840300 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2840301 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2840301 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
> [junit4] 2> "operation":"state",
> [junit4] 2> "state":"down",
> [junit4] 2> "base_url":"http://127.0.0.1:38382",
> [junit4] 2> "core":"collection1",
> [junit4] 2> "roles":null,
> [junit4] 2> "node_name":"127.0.0.1:38382_",
> [junit4] 2> "shard":null,
> [junit4] 2> "shard_range":null,
> [junit4] 2> "shard_state":"active",
> [junit4] 2> "shard_parent":null,
> [junit4] 2> "collection":"collection1",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "core_node_name":null}
> [junit4] 2> 2840302 T7713 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
> [junit4] 2> 2840302 T7713 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
> [junit4] 2> 2840305 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2840408 T7757 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> 2840408 T7712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
> [junit4] 2> 2840408 T7722 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> 2840408 T7737 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> 2841301 T7758 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
> [junit4] 2> 2841301 T7758 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/collection1
> [junit4] 2> 2841301 T7758 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
> [junit4] 2> 2841302 T7758 oasc.ZkController.createCollectionZkNode Collection zkNode exists
> [junit4] 2> 2841303 T7758 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
> [junit4] 2> 2841303 T7758 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/collection1/'
> [junit4] 2> 2841305 T7758 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/collection1/lib/README' to classloader
> [junit4] 2> 2841306 T7758 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/collection1/lib/classes/' to classloader
> [junit4] 2> 2841370 T7758 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
> [junit4] 2> 2841442 T7758 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
> [junit4] 2> 2841543 T7758 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
> [junit4] 2> 2841553 T7758 oass.IndexSchema.readSchema [collection1] Schema name=test
> [junit4] 2> 2841996 T7758 oass.IndexSchema.readSchema default search field in schema is text
> [junit4] 2> 2841999 T7758 oass.IndexSchema.readSchema unique key field: id
> [junit4] 2> 2842000 T7758 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 2842004 T7758 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 2842018 T7758 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
> [junit4] 2> 2842018 T7758 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1388944898982/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty2/
> [junit4] 2> 2842018 T7758 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6c2bae18
> [junit4] 2> 2842019 T7758 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty2
> [junit4] 2> 2842019 T7758 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty2/index/
> [junit4] 2> 2842019 T7758 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty2/index' doesn't exist. Creating new index...
> [junit4] 2> 2842020 T7758 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty2/index
> [junit4] 2> 2842021 T7758 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=51.1748046875, floorSegmentMB=1.01953125, forceMergeDeletesPctAllowed=20.22639910826647, segmentsPerTier=17.0, maxCFSSegmentSizeMB=1.361328125, noCFSRatio=1.0
> [junit4] 2> 2842021 T7758 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4fdd011 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5289967c; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
> [junit4] 2> 2842022 T7758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 2842024 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
> [junit4] 2> 2842025 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
> [junit4] 2> 2842025 T7758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
> [junit4] 2> 2842025 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
> [junit4] 2> 2842025 T7758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
> [junit4] 2> 2842025 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
> [junit4] 2> 2842026 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 2842026 T7758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
> [junit4] 2> 2842026 T7758 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
> [junit4] 2> 2842027 T7758 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
> [junit4] 2> 2842027 T7758 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
> [junit4] 2> 2842027 T7758 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
> [junit4] 2> 2842027 T7758 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
> [junit4] 2> 2842028 T7758 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
> [junit4] 2> 2842028 T7758 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
> [junit4] 2> 2842029 T7758 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
> [junit4] 2> 2842029 T7758 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
> [junit4] 2> 2842040 T7758 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
> [junit4] 2> 2842043 T7758 oasu.CommitTracker.<init> Hard AutoCommit: disabled
> [junit4] 2> 2842044 T7758 oasu.CommitTracker.<init> Soft AutoCommit: disabled
> [junit4] 2> 2842044 T7758 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=16, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5898393679458741]
> [junit4] 2> 2842044 T7758 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4fdd011 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5289967c; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
> [junit4] 2> 2842045 T7758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 2842045 T7758 oass.SolrIndexSearcher.<init> Opening Searcher@2f5b1603 main
> [junit4] 2> 2842047 T7759 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2f5b1603 main{StandardDirectoryReader(segments_1:1:nrt)}
> [junit4] 2> 2842049 T7758 oasc.CoreContainer.registerCore registering core: collection1
> [junit4] 2> 2842049 T7686 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
> [junit4] 2> 2842050 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
> [junit4] 2> 2842049 T7762 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38382 collection:collection1 shard:shard2
> [junit4] 2> 2842051 T7762 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
> [junit4] 2> 2842067 T7762 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
> [junit4] 2> 2842069 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2842069 T7762 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
> [junit4] 2> 2842069 T7762 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
> [junit4] 2> 2842069 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> ASYNC NEW_CORE C2591 name=collection1 org.apache.solr.core.SolrCore@3327f008 url=http://127.0.0.1:38382/collection1 node=127.0.0.1:38382_ C2591_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:38382, core=collection1, node_name=127.0.0.1:38382_}
> [junit4] 2> 2842069 T7762 C2591 P38382 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38382/collection1/
> [junit4] 2> 2842070 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2842070 T7762 C2591 P38382 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
> [junit4] 2> 2842070 T7762 C2591 P38382 oasc.SyncStrategy.syncToMe http://127.0.0.1:38382/collection1/ has no replicas
> [junit4] 2> 2842070 T7762 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38382/collection1/ shard2
> [junit4] 2> 2842070 T7762 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
> [junit4] 2> 2842071 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2842074 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2842075 T7757 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> 2842075 T7737 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> 2842075 T7722 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> 2842075 T7712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
> [junit4] 2> 2842077 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2842080 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2842183 T7757 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> 2842183 T7722 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> 2842183 T7737 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> 2842183 T7712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
> [junit4] 2> 2842228 T7762 oasc.ZkController.register We are http://127.0.0.1:38382/collection1/ and leader is http://127.0.0.1:38382/collection1/
> [junit4] 2> 2842228 T7762 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38382
> [junit4] 2> 2842228 T7762 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
> [junit4] 2> 2842228 T7762 oasc.ZkController.publish publishing core=collection1 state=active
> [junit4] 2> 2842228 T7762 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
> [junit4] 2> 2842230 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2842230 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2842230 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2842230 T7762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2842231 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2842231 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
> [junit4] 2> "operation":"state",
> [junit4] 2> "state":"active",
> [junit4] 2> "base_url":"http://127.0.0.1:38382",
> [junit4] 2> "core":"collection1",
> [junit4] 2> "roles":null,
> [junit4] 2> "node_name":"127.0.0.1:38382_",
> [junit4] 2> "shard":"shard2",
> [junit4] 2> "shard_range":null,
> [junit4] 2> "shard_state":"active",
> [junit4] 2> "shard_parent":null,
> [junit4] 2> "collection":"collection1",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "core_node_name":"core_node2"}
> [junit4] 2> 2842232 T7686 oejs.Server.doStart jetty-8.1.10.v20130312
> [junit4] 2> 2842234 T7686 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:45611
> [junit4] 2> 2842234 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2842235 T7686 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
> [junit4] 2> 2842235 T7686 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
> [junit4] 2> 2842235 T7686 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208
> [junit4] 2> 2842236 T7686 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/'
> [junit4] 2> 2842262 T7686 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/solr.xml
> [junit4] 2> 2842323 T7686 oasc.CoreContainer.<init> New CoreContainer 1245378889
> [junit4] 2> 2842323 T7686 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/]
> [junit4] 2> 2842324 T7686 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
> [junit4] 2> 2842325 T7686 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
> [junit4] 2> 2842325 T7686 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
> [junit4] 2> 2842325 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
> [junit4] 2> 2842326 T7686 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
> [junit4] 2> 2842326 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
> [junit4] 2> 2842326 T7686 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
> [junit4] 2> 2842326 T7686 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
> [junit4] 2> 2842327 T7686 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
> [junit4] 2> 2842334 T7686 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
> [junit4] 2> 2842335 T7686 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
> [junit4] 2> 2842335 T7686 oasc.CoreContainer.load Host Name: 127.0.0.1
> [junit4] 2> 2842335 T7686 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60363/solr
> [junit4] 2> 2842336 T7686 oasc.ZkController.checkChrootPath zkHost includes chroot
> [junit4] 2> 2842336 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 2842338 T7757 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> 2842338 T7722 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> 2842338 T7737 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> 2842338 T7712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
> [junit4] 2> 2842340 T7774 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56c01a65 name:ZooKeeperConnection Watcher:127.0.0.1:60363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 2842340 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 2842351 T7686 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
> [junit4] 2> 2842353 T7777 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23b0b33d name:ZooKeeperConnection Watcher:127.0.0.1:60363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
> [junit4] 2> 2842354 T7686 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
> [junit4] 2> 2842363 T7686 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
> [junit4] 2> 2843366 T7686 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45611_
> [junit4] 2> 2843394 T7686 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45611_
> [junit4] 2> 2843397 T7777 oascc.ZkStateReader$3.process Updating live nodes... (4)
> [junit4] 2> 2843398 T7737 oascc.ZkStateReader$3.process Updating live nodes... (4)
> [junit4] 2> 2843398 T7712 oascc.ZkStateReader$3.process Updating live nodes... (4)
> [junit4] 2> 2843398 T7757 oascc.ZkStateReader$3.process Updating live nodes... (4)
> [junit4] 2> 2843397 T7722 oascc.ZkStateReader$3.process Updating live nodes... (4)
> [junit4] 2> 2843415 T7778 oasc.ZkController.publish publishing core=collection1 state=down
> [junit4] 2> 2843415 T7778 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
> [junit4] 2> 2843416 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2843416 T7778 oasc.ZkController.waitForCoreNodeName look for our core node name
> [junit4] 2> 2843417 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2843417 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2843418 T7713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
> [junit4] 2> 2843418 T7713 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
> [junit4] 2> "operation":"state",
> [junit4] 2> "state":"down",
> [junit4] 2> "base_url":"http://127.0.0.1:45611",
> [junit4] 2> "core":"collection1",
> [junit4] 2> "roles":null,
> [junit4] 2> "node_name":"127.0.0.1:45611_",
> [junit4] 2> "shard":null,
> [junit4] 2> "shard_range":null,
> [junit4] 2> "shard_state":"active",
> [junit4] 2> "shard_parent":null,
> [junit4] 2> "collection":"collection1",
> [junit4] 2> "numShards":"2",
> [junit4] 2> "core_node_name":null}
> [junit4] 2> 2843418 T7713 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
> [junit4] 2> 2843419 T7713 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
> [junit4] 2> 2843422 T7712 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
> [junit4] 2> 2843524 T7722 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> 2843524 T7737 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> 2843524 T7757 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> 2843524 T7777 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> 2843524 T7712 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> 2844418 T7778 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
> [junit4] 2> 2844418 T7778 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/collection1
> [junit4] 2> 2844418 T7778 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
> [junit4] 2> 2844419 T7778 oasc.ZkController.createCollectionZkNode Collection zkNode exists
> [junit4] 2> 2844419 T7778 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
> [junit4] 2> 2844420 T7778 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/collection1/'
> [junit4] 2> 2844421 T7778 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/collection1/lib/classes/' to classloader
> [junit4] 2> 2844422 T7778 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/collection1/lib/README' to classloader
> [junit4] 2> 2844466 T7778 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
> [junit4] 2> 2844508 T7778 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
> [junit4] 2> 2844610 T7778 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
> [junit4] 2> 2844617 T7778 oass.IndexSchema.readSchema [collection1] Schema name=test
> [junit4] 2> 2845020 T7778 oass.IndexSchema.readSchema default search field in schema is text
> [junit4] 2> 2845023 T7778 oass.IndexSchema.readSchema unique key field: id
> [junit4] 2> 2845025 T7778 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 2845028 T7778 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
> [junit4] 2> 2845043 T7778 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
> [junit4] 2> 2845043 T7778 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1388944902208/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty3/
> [junit4] 2> 2845043 T7778 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6c2bae18
> [junit4] 2> 2845044 T7778 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty3
> [junit4] 2> 2845044 T7778 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty3/index/
> [junit4] 2> 2845044 T7778 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty3/index' doesn't exist. Creating new index...
> [junit4] 2> 2845046 T7778 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1388944892811/jetty3/index
> [junit4] 2> 2845046 T7778 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=51.1748046875, floorSegmentMB=1.01953125, forceMergeDeletesPctAllowed=20.22639910826647, segmentsPerTier=17.0, maxCFSSegmentSizeMB=1.361328125, noCFSRatio=1.0
> [junit4] 2> 2845047 T7778 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
> [junit4] 2> commit{dir=MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@69634371 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e64b14d; maxCacheMB=0.0107421875 maxMergeSizeMB=0.953125)),segFN=segments_1,generation=1}
> [junit4] 2> 2845047 T7778 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
> [junit4] 2> 2845050 T7778 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
> [junit4] 2> 2845050 T7778 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
> [junit4] 2> 2845050 T7778 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
> [junit4] 2> 2845051 T7778 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
> [junit4] 2> 2845051 T7778 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_s
>
> [...truncated too long message...]
>
> a:519)
> [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
> [junit4] 2>
> [junit4] 2> 3169708 T7798 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:256)
> [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
> [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:253)
> [junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
> [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:138)
> [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> 337466 T7685 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
> [junit4] 2> 357525 T7685 ccr.ThreadLeakControl.checkThreadLeaks SEVERE 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest:
> [junit4] 2> 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
> [junit4] 2> at java.lang.Object.wait(Native Method)
> [junit4] 2> at java.lang.Object.wait(Object.java:503)
> [junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:526)
> [junit4] 2> at java.util.TimerThread.run(Timer.java:505)
> [junit4] 2> 357526 T7685 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
> [junit4] 2> 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
> [junit4] 2> 360533 T7685 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
> [junit4] 2> 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
> [junit4] 2> at java.lang.Object.wait(Native Method)
> [junit4] 2> at java.lang.Object.wait(Object.java:503)
> [junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:526)
> [junit4] 2> at java.util.TimerThread.run(Timer.java:505)
> [junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=pl_PL, timezone=Africa/Sao_Tome
> [junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=2,free=279178864,total=494141440
> [junit4] 2> NOTE: All tests run in this JVM: [TestUniqueKeyFieldResource, RAMDirectoryFactoryTest, DistributedSuggestComponentTest, TestComponentsName, BasicZkTest, ShardRoutingCustomTest, CollectionsAPIDistributedZkTest, SpellingQueryConverterTest, DirectSolrConnectionTest, TestNumberUtils, SolrCmdDistributorTest, TestAnalyzedSuggestions, TestAddFieldRealTimeGet, TestSolrQueryParserDefaultOperatorResource, HighlighterTest, ChangedSchemaMergeTest, TestUpdate, RequiredFieldsTest, BlockDirectoryTest, SimplePostToolTest, TestRangeQuery, TestSolrDeletionPolicy2, AlternateDirectoryTest, TestIndexSearcher, IndexBasedSpellCheckerTest, AliasIntegrationTest, TestBinaryResponseWriter, AddBlockUpdateTest, TestClassNameShortening, TestFastLRUCache, DateFieldTest, TestStressReorder, OutputWriterTest, TestFoldingMultitermQuery, MinimalSchemaTest, TestCoreDiscovery, TestHashPartitioner, TestFieldTypeCollectionResource, TestOmitPositions, TestSolrQueryParserResource, ZkSolrClientTest, TestRTGBase, RequestHandlersTest, TestNRTOpen, StatsComponentTest, TimeZoneUtilsTest, BlockCacheTest, ConnectionManagerTest, TestAtomicUpdateErrorCases, TestSolrXmlPersistence, TestArbitraryIndexDir, StressHdfsTest, TestSweetSpotSimilarityFactory, TestBinaryField, TestStressRecovery, SolrPluginUtilsTest, TestZkChroot, SpellCheckCollatorTest, TestCSVLoader, DebugComponentTest, TestSolr4Spatial, TestDFRSimilarityFactory, XsltUpdateRequestHandlerTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestIBSimilarityFactory, OpenExchangeRatesOrgProviderTest, ChaosMonkeySafeLeaderTest, TestIndexingPerformance, TestCodecSupport, FieldAnalysisRequestHandlerTest, UniqFieldsUpdateProcessorFactoryTest, DocValuesMultiTest, TestSolrJ, TestQuerySenderListener, DistributedQueryComponentCustomSortTest, TestRandomMergePolicy, FieldFacetExtrasTest, DefaultValueUpdateProcessorTest, TestPhraseSuggestions, IndexSchemaRuntimeFieldTest, CachingDirectoryFactoryTest, TestDistribDocBasedVersion, StandardRequestHandlerTest, AbstractAnalyticsStatsTest, TestFastWriter, QueryFacetTest, TestFieldResource, BadIndexSchemaTest, BasicDistributedZk2Test, SyncSliceTest, LeaderElectionIntegrationTest, ClusterStateUpdateTest, TestRandomFaceting, TestDistributedGrouping, TestFaceting, TestRecovery, TermVectorComponentDistributedTest, ZkControllerTest, TestRealTimeGet, TestJoin, TestMultiCoreConfBootstrap, TestReload, TestCoreContainer, TestGroupingSearch, DirectUpdateHandlerTest, OverseerCollectionProcessorTest, CurrencyFieldOpenExchangeTest, SolrIndexSplitterTest, AnalysisAfterCoreReloadTest, SolrRequestParserTest, TestStressLucene, PolyFieldTest, SolrCoreCheckLockOnStartupTest, TestWordDelimiterFilterFactory, SortByFunctionTest, TestSolrDeletionPolicy1, LukeRequestHandlerTest, DirectSolrSpellCheckerTest, TestQueryTypes, TermsComponentTest, TestValueSourceCache, FastVectorHighlighterTest, TestJmxIntegration, TestCSVResponseWriter, JsonLoaderTest, TestPHPSerializedResponseWriter, SearchHandlerTest, HighlighterConfigTest, UpdateParamsTest, TestQuerySenderNoQuery, ResponseLogComponentTest, BadComponentTest, TestSearchPerf, TestFuzzyAnalyzedSuggestions, TestSolrCoreProperties, NotRequiredUniqueKeyTest, TestLuceneMatchVersion, TestPerFieldSimilarity, TestDefaultSimilarityFactory, TestFastOutputStream, URLClassifyProcessorTest, PreAnalyzedFieldTest, PrimUtilsTest, TestUtils, TestDocumentBuilder, ZkNodePropsTest, SystemInfoHandlerTest, FileUtilsTest, SolrTestCaseJ4Test, TestDistributedMissingSort, ExpressionTest, AbstractAnalyticsFacetTest, FieldFacetTest, FunctionTest, AssignTest, DeleteReplicaTest, DeleteShardTest, MigrateRouteKeyTest, ShardSplitTest]
> [junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
> [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ShardSplitTest -Dtests.seed=2B6E400BDCDB9BD9 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=pl_PL -Dtests.timezone=Africa/Sao_Tome -Dtests.file.encoding=UTF-8
> [junit4] ERROR 0.00s J1 | ShardSplitTest (suite) <<<
> [junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardSplitTest:
> [junit4] > 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
> [junit4] > at java.lang.Object.wait(Native Method)
> [junit4] > at java.lang.Object.wait(Object.java:503)
> [junit4] > at java.util.TimerThread.mainLoop(Timer.java:526)
> [junit4] > at java.util.TimerThread.run(Timer.java:505)
> [junit4] > at __randomizedtesting.SeedInfo.seed([2B6E400BDCDB9BD9]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
> [junit4] > 1) Thread[id=7986, name=Timer-351, state=WAITING, group=TGRP-ShardSplitTest]
> [junit4] > at java.lang.Object.wait(Native Method)
> [junit4] > at java.lang.Object.wait(Object.java:503)
> [junit4] > at java.util.TimerThread.mainLoop(Timer.java:526)
> [junit4] > at java.util.TimerThread.run(Timer.java:505)
> [junit4] > at __randomizedtesting.SeedInfo.seed([2B6E400BDCDB9BD9]:0)
> [junit4] Completed on J1 in 360.59s, 1 test, 2 errors <<< FAILURES!
>
> [...truncated 13 lines...]
> BUILD FAILED
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:460: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:433: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:39: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:37: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:189: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:491: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1304: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:937: There were test failures: 358 suites, 1577 tests, 2 suite-level errors, 33 ignored (4 assumptions)
>
> Total time: 116 minutes 37 seconds
> Build step 'Invoke Ant' marked build as failure
> Archiving artifacts
> Recording test results
> Email was triggered for: Failure
> Sending email for trigger: Failure
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org