You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/02/21 20:41:17 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.6.0) - Build # 1321 -
Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1321/
Java: 64bit/jdk1.6.0 -XX:-UseCompressedOops -XX:+UseParallelGC
2 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([B5BEE0A4A7FF4210]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([B5BEE0A4A7FF4210]:0)
Build Log:
[...truncated 9916 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> 1285887 T5296 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 1285888 T5296 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /df/i
[junit4] 2> 1285892 T5296 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeySafeLeaderTest-1393004299850
[junit4] 2> 1285893 T5296 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1285894 T5297 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1285997 T5296 oasc.ZkTestServer.run start zk server on port:54296
[junit4] 2> 1285999 T5296 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1286006 T5303 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bf75fd7 name:ZooKeeperConnection Watcher:127.0.0.1:54296 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1286006 T5296 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1286007 T5296 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1286024 T5296 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1286028 T5305 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@639b0cc9 name:ZooKeeperConnection Watcher:127.0.0.1:54296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1286029 T5296 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1286029 T5296 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1286039 T5296 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1286049 T5296 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1286056 T5296 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1286065 T5296 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1286066 T5296 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1286079 T5296 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 1286080 T5296 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1286090 T5296 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1286091 T5296 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1286102 T5296 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1286103 T5296 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1286112 T5296 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1286113 T5296 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1286123 T5296 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1286124 T5296 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1286134 T5296 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1286135 T5296 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1286144 T5296 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1286145 T5296 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1286154 T5296 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1286154 T5296 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1286164 T5296 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1286164 T5296 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1286173 T5296 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1286174 T5296 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1286470 T5296 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1286478 T5296 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54299
[junit4] 2> 1286479 T5296 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1286480 T5296 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1286481 T5296 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393004300143
[junit4] 2> 1286481 T5296 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393004300143/'
[junit4] 2> 1286507 T5296 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393004300143/solr.xml
[junit4] 2> 1286548 T5296 oasc.CoreContainer.<init> New CoreContainer 460947780
[junit4] 2> 1286548 T5296 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393004300143/]
[junit4] 2> 1286549 T5296 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1286550 T5296 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1286550 T5296 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1286551 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1286552 T5296 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1286552 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1286553 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1286553 T5296 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1286553 T5296 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1286575 T5296 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1286576 T5296 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1286576 T5296 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1286577 T5296 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54296/solr
[junit4] 2> 1286577 T5296 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1286578 T5296 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1286582 T5316 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4615a573 name:ZooKeeperConnection Watcher:127.0.0.1:54296 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1286583 T5296 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1286588 T5296 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1286592 T5318 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dbe2676 name:ZooKeeperConnection Watcher:127.0.0.1:54296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1286592 T5296 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1286597 T5296 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1286608 T5296 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1286620 T5296 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1286627 T5296 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54299_df%2Fi
[junit4] 2> 1286629 T5296 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54299_df%2Fi
[junit4] 2> 1286640 T5296 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1286647 T5296 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1286661 T5296 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54299_df%2Fi
[junit4] 2> 1286662 T5296 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1286669 T5296 oasc.Overseer.start Overseer (id=91291929795362819-127.0.0.1:54299_df%2Fi-n_0000000000) starting
[junit4] 2> 1286680 T5296 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1286693 T5320 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1286695 T5296 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1286696 T5320 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1286706 T5296 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1286712 T5296 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1286722 T5319 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1286728 T5321 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1286729 T5321 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1286731 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1286731 T5321 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1286736 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1286738 T5319 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:54299/df/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54299_df%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1286738 T5319 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1286738 T5319 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1286746 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1286748 T5318 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> 1287734 T5321 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1287734 T5321 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393004300143/collection1
[junit4] 2> 1287734 T5321 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1287737 T5321 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1287738 T5321 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1287742 T5321 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1287742 T5321 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393004300143/collection1/'
[junit4] 2> 1287743 T5321 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393004300143/collection1/lib/classes/' to classloader
[junit4] 2> 1287744 T5321 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393004300143/collection1/lib/README' to classloader
[junit4] 2> 1287792 T5321 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1287828 T5321 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1287832 T5321 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1287855 T5321 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1288193 T5321 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1288196 T5321 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1288196 T5321 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1288204 T5321 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1288282 T5321 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1288282 T5321 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1393004300143/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/control/data/
[junit4] 2> 1288283 T5321 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@69c67db
[junit4] 2> 1288284 T5321 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/control/data
[junit4] 2> 1288284 T5321 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/control/data/index/
[junit4] 2> 1288285 T5321 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1288285 T5321 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/control/data/index
[junit4] 2> 1288286 T5321 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=45, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=42.1005859375, floorSegmentMB=1.365234375, forceMergeDeletesPctAllowed=7.950519174065253, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1288289 T5321 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 1288290 T5321 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1288292 T5321 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1288293 T5321 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1288293 T5321 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1288293 T5321 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1288293 T5321 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1288294 T5321 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1288294 T5321 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1288294 T5321 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1288295 T5321 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1288295 T5321 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1288296 T5321 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1288296 T5321 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1288296 T5321 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1288297 T5321 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1288298 T5321 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1288298 T5321 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1288304 T5321 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1288307 T5321 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1288307 T5321 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1288308 T5321 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=44, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1288309 T5321 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 1288309 T5321 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1288310 T5321 oass.SolrIndexSearcher.<init> Opening Searcher@4cff9388[collection1] main
[junit4] 2> 1288315 T5322 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4cff9388[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1288316 T5321 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1288318 T5296 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1288319 T5296 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1288318 T5325 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54299/df/i collection:control_collection shard:shard1
[junit4] 2> 1288321 T5296 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1288324 T5325 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1288325 T5327 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a8fc6f2 name:ZooKeeperConnection Watcher:127.0.0.1:54296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1288325 T5296 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1288333 T5296 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1288345 T5296 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1288352 T5325 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1288357 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1288360 T5325 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1288360 T5325 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1220 name=collection1 org.apache.solr.core.SolrCore@4c85f056 url=http://127.0.0.1:54299/df/i/collection1 node=127.0.0.1:54299_df%2Fi C1220_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:54299/df/i, core=collection1, node_name=127.0.0.1:54299_df%2Fi}
[junit4] 2> 1288361 T5325 C1220 P54299 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54299/df/i/collection1/
[junit4] 2> 1288361 T5325 C1220 P54299 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1288361 T5325 C1220 P54299 oasc.SyncStrategy.syncToMe http://127.0.0.1:54299/df/i/collection1/ has no replicas
[junit4] 2> 1288362 T5325 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54299/df/i/collection1/ shard1
[junit4] 2> 1288362 T5325 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1288368 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1288389 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1288392 T5327 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> 1288395 T5318 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> 1288412 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1288421 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1288529 T5327 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> 1288530 T5318 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> 1288555 T5325 oasc.ZkController.register We are http://127.0.0.1:54299/df/i/collection1/ and leader is http://127.0.0.1:54299/df/i/collection1/
[junit4] 2> 1288556 T5325 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54299/df/i
[junit4] 2> 1288556 T5325 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1288556 T5325 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1288556 T5325 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1288559 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1288559 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1288559 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1288564 T5325 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1288567 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1288568 T5319 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:54299/df/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54299_df%2Fi",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1288576 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1288684 T5318 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> 1288685 T5327 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> 1288697 T5296 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 1288699 T5296 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1288705 T5296 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54303
[junit4] 2> 1288705 T5296 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1288706 T5296 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1288706 T5296 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1393004302303
[junit4] 2> 1288707 T5296 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1393004302303/'
[junit4] 2> 1288735 T5296 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1393004302303/solr.xml
[junit4] 2> 1288787 T5296 oasc.CoreContainer.<init> New CoreContainer 115298146
[junit4] 2> 1288788 T5296 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1393004302303/]
[junit4] 2> 1288789 T5296 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1288789 T5296 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1288790 T5296 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1288790 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1288791 T5296 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1288791 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1288791 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1288791 T5296 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1288792 T5296 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1288814 T5296 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1288814 T5296 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1288815 T5296 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1288815 T5296 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54296/solr
[junit4] 2> 1288816 T5296 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1288817 T5296 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1288821 T5338 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ed4ae74 name:ZooKeeperConnection Watcher:127.0.0.1:54296 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1288822 T5296 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1288827 T5296 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1288831 T5340 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16b5dc76 name:ZooKeeperConnection Watcher:127.0.0.1:54296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1288831 T5296 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1288847 T5296 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1289859 T5296 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54303_df%2Fi
[junit4] 2> 1289862 T5296 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54303_df%2Fi
[junit4] 2> 1289872 T5327 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1289873 T5340 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1289874 T5318 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1289891 T5341 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1289892 T5341 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1289894 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1289894 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1289895 T5341 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1289895 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1289901 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1289902 T5319 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:54303/df/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54303_df%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1289902 T5319 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1289903 T5319 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1289911 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1290021 T5318 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> 1290021 T5327 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> 1290021 T5340 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> 1290896 T5341 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1290898 T5341 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1393004302303/collection1
[junit4] 2> 1290898 T5341 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1290900 T5341 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1290900 T5341 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1290904 T5341 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1290904 T5341 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1393004302303/collection1/'
[junit4] 2> 1290905 T5341 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1393004302303/collection1/lib/classes/' to classloader
[junit4] 2> 1290906 T5341 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1393004302303/collection1/lib/README' to classloader
[junit4] 2> 1290955 T5341 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1290994 T5341 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1290998 T5341 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1291006 T5341 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1291346 T5341 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1291349 T5341 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1291350 T5341 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1291357 T5341 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1291436 T5341 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1291437 T5341 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1393004302303/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty1/
[junit4] 2> 1291437 T5341 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@69c67db
[junit4] 2> 1291438 T5341 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty1
[junit4] 2> 1291439 T5341 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty1/index/
[junit4] 2> 1291439 T5341 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1291441 T5341 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty1/index
[junit4] 2> 1291442 T5341 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=45, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=42.1005859375, floorSegmentMB=1.365234375, forceMergeDeletesPctAllowed=7.950519174065253, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1291445 T5341 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 1291445 T5341 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1291450 T5341 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1291451 T5341 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1291451 T5341 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1291451 T5341 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1291451 T5341 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1291452 T5341 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1291452 T5341 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1291452 T5341 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1291453 T5341 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1291453 T5341 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1291454 T5341 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1291454 T5341 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1291455 T5341 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1291455 T5341 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1291456 T5341 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1291456 T5341 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1291462 T5341 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1291465 T5341 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1291466 T5341 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1291467 T5341 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=44, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1291468 T5341 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 1291468 T5341 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1291468 T5341 oass.SolrIndexSearcher.<init> Opening Searcher@482518cd[collection1] main
[junit4] 2> 1291474 T5342 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@482518cd[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1291478 T5341 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1291480 T5296 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1291480 T5296 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1291480 T5345 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54303/df/i collection:collection1 shard:shard1
[junit4] 2> 1291485 T5345 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1291505 T5345 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1291511 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1291511 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1291512 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1291513 T5345 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1291513 T5345 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1221 name=collection1 org.apache.solr.core.SolrCore@373453c0 url=http://127.0.0.1:54303/df/i/collection1 node=127.0.0.1:54303_df%2Fi C1221_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:54303/df/i, core=collection1, node_name=127.0.0.1:54303_df%2Fi}
[junit4] 2> 1291514 T5345 C1221 P54303 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54303/df/i/collection1/
[junit4] 2> 1291514 T5345 C1221 P54303 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1291514 T5345 C1221 P54303 oasc.SyncStrategy.syncToMe http://127.0.0.1:54303/df/i/collection1/ has no replicas
[junit4] 2> 1291515 T5345 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54303/df/i/collection1/ shard1
[junit4] 2> 1291515 T5345 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1291527 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1291543 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1291548 T5318 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> 1291548 T5340 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> 1291556 T5327 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> 1291568 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1291576 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1291683 T5327 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> 1291684 T5340 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> 1291684 T5318 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> 1291708 T5345 oasc.ZkController.register We are http://127.0.0.1:54303/df/i/collection1/ and leader is http://127.0.0.1:54303/df/i/collection1/
[junit4] 2> 1291708 T5345 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54303/df/i
[junit4] 2> 1291708 T5345 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1291709 T5345 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1291709 T5345 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1291711 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1291711 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1291712 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1291713 T5345 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1291720 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1291722 T5319 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:54303/df/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54303_df%2Fi",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1291728 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1291801 T5296 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 1291802 T5296 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1291807 T5296 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54306
[junit4] 2> 1291808 T5296 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1291809 T5296 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1291811 T5296 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393004305438
[junit4] 2> 1291812 T5296 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393004305438/'
[junit4] 2> 1291835 T5327 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> 1291835 T5340 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> 1291835 T5318 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> 1291850 T5296 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393004305438/solr.xml
[junit4] 2> 1291893 T5296 oasc.CoreContainer.<init> New CoreContainer 1155558982
[junit4] 2> 1291894 T5296 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393004305438/]
[junit4] 2> 1291895 T5296 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1291895 T5296 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1291896 T5296 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1291896 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1291897 T5296 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1291897 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1291897 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1291898 T5296 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1291898 T5296 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1291919 T5296 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1291920 T5296 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1291920 T5296 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1291921 T5296 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54296/solr
[junit4] 2> 1291922 T5296 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1291923 T5296 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1291927 T5356 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a67d8fd name:ZooKeeperConnection Watcher:127.0.0.1:54296 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1291927 T5296 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1291933 T5296 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1291937 T5358 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a375be9 name:ZooKeeperConnection Watcher:127.0.0.1:54296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1291938 T5296 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1291951 T5296 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1292964 T5296 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54306_df%2Fi
[junit4] 2> 1292967 T5296 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54306_df%2Fi
[junit4] 2> 1292977 T5318 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1292977 T5340 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1292978 T5327 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1292980 T5358 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1292996 T5359 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1292996 T5359 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1292999 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1292999 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1292999 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1292999 T5359 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1293004 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1293006 T5319 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:54306/df/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54306_df%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1293006 T5319 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1293006 T5319 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1293016 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1293124 T5327 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> 1293124 T5358 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> 1293124 T5318 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> 1293125 T5340 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> 1294001 T5359 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1294002 T5359 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393004305438/collection1
[junit4] 2> 1294002 T5359 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1294004 T5359 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1294005 T5359 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1294009 T5359 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1294009 T5359 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393004305438/collection1/'
[junit4] 2> 1294010 T5359 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393004305438/collection1/lib/classes/' to classloader
[junit4] 2> 1294010 T5359 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393004305438/collection1/lib/README' to classloader
[junit4] 2> 1294056 T5359 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1294091 T5359 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1294096 T5359 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1294103 T5359 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1294432 T5359 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1294435 T5359 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1294436 T5359 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1294443 T5359 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1294518 T5359 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1294519 T5359 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1393004305438/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty2/
[junit4] 2> 1294519 T5359 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@69c67db
[junit4] 2> 1294520 T5359 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty2
[junit4] 2> 1294521 T5359 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty2/index/
[junit4] 2> 1294521 T5359 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1294522 T5359 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty2/index
[junit4] 2> 1294522 T5359 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=45, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=42.1005859375, floorSegmentMB=1.365234375, forceMergeDeletesPctAllowed=7.950519174065253, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1294525 T5359 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 1294526 T5359 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1294529 T5359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1294529 T5359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1294530 T5359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1294530 T5359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1294530 T5359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1294531 T5359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1294531 T5359 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1294531 T5359 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1294531 T5359 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1294532 T5359 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1294533 T5359 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1294533 T5359 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1294533 T5359 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1294535 T5359 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1294536 T5359 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1294536 T5359 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1294542 T5359 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1294545 T5359 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1294545 T5359 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1294546 T5359 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=44, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1294547 T5359 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 1294547 T5359 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1294548 T5359 oass.SolrIndexSearcher.<init> Opening Searcher@52dccaed[collection1] main
[junit4] 2> 1294554 T5360 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@52dccaed[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1294557 T5359 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1294559 T5296 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1294559 T5296 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1294559 T5363 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54306/df/i collection:collection1 shard:shard2
[junit4] 2> 1294565 T5363 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1294584 T5363 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1294592 T5363 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1294592 T5363 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1222 name=collection1 org.apache.solr.core.SolrCore@1c2c347d url=http://127.0.0.1:54306/df/i/collection1 node=127.0.0.1:54306_df%2Fi C1222_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:54306/df/i, core=collection1, node_name=127.0.0.1:54306_df%2Fi}
[junit4] 2> 1294593 T5363 C1222 P54306 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54306/df/i/collection1/
[junit4] 2> 1294593 T5363 C1222 P54306 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1294593 T5363 C1222 P54306 oasc.SyncStrategy.syncToMe http://127.0.0.1:54306/df/i/collection1/ has no replicas
[junit4] 2> 1294593 T5363 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54306/df/i/collection1/ shard2
[junit4] 2> 1294594 T5363 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1294593 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1294594 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1294594 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1294604 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1294616 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1294624 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1294636 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1294639 T5358 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> 1294639 T5318 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> 1294646 T5327 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> 1294653 T5340 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> 1294678 T5363 oasc.ZkController.register We are http://127.0.0.1:54306/df/i/collection1/ and leader is http://127.0.0.1:54306/df/i/collection1/
[junit4] 2> 1294678 T5363 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54306/df/i
[junit4] 2> 1294678 T5363 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1294679 T5363 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1294679 T5363 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1294681 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1294685 T5363 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1294689 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1294691 T5319 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:54306/df/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54306_df%2Fi",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1294699 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1294809 T5340 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> 1294809 T5327 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> 1294810 T5358 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> 1294810 T5318 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> 1294901 T5296 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 1294902 T5296 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1294906 T5296 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54309
[junit4] 2> 1294906 T5296 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1294907 T5296 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1294907 T5296 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1393004308517
[junit4] 2> 1294908 T5296 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1393004308517/'
[junit4] 2> 1294935 T5296 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1393004308517/solr.xml
[junit4] 2> 1294976 T5296 oasc.CoreContainer.<init> New CoreContainer 1567904270
[junit4] 2> 1294976 T5296 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1393004308517/]
[junit4] 2> 1294978 T5296 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1294978 T5296 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1294978 T5296 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1294979 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1294979 T5296 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1294979 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1294980 T5296 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1294980 T5296 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1294981 T5296 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1295003 T5296 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1295004 T5296 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1295004 T5296 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1295005 T5296 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54296/solr
[junit4] 2> 1295005 T5296 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1295007 T5296 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1295011 T5374 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7fb74510 name:ZooKeeperConnection Watcher:127.0.0.1:54296 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1295011 T5296 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1295017 T5296 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1295021 T5376 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2747c021 name:ZooKeeperConnection Watcher:127.0.0.1:54296/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1295021 T5296 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1295036 T5296 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1296048 T5296 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54309_df%2Fi
[junit4] 2> 1296051 T5296 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54309_df%2Fi
[junit4] 2> 1296063 T5327 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1296063 T5318 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1296064 T5358 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1296066 T5340 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1296066 T5376 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1296084 T5377 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1296084 T5377 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1296087 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1296087 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1296088 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1296088 T5377 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1296093 T5319 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1296095 T5319 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:54309/df/i",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54309_df%2Fi",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1296095 T5319 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1296095 T5319 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1296103 T5318 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1296212 T5340 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> 1296212 T5358 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> 1296213 T5318 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> 1296213 T5376 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> 1296214 T5327 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> 1297090 T5377 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1297090 T5377 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1393004308517/collection1
[junit4] 2> 1297091 T5377 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1297093 T5377 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1297093 T5377 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1297096 T5377 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1297096 T5377 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1393004308517/collection1/'
[junit4] 2> 1297098 T5377 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1393004308517/collection1/lib/classes/' to classloader
[junit4] 2> 1297099 T5377 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1393004308517/collection1/lib/README' to classloader
[junit4] 2> 1297159 T5377 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1297195 T5377 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1297200 T5377 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1297207 T5377 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1297538 T5377 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1297540 T5377 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1297542 T5377 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1297547 T5377 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1297632 T5377 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1297633 T5377 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1393004308517/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty3/
[junit4] 2> 1297633 T5377 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@69c67db
[junit4] 2> 1297634 T5377 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty3
[junit4] 2> 1297634 T5377 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty3/index/
[junit4] 2> 1297634 T5377 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1297635 T5377 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty3/index
[junit4] 2> 1297635 T5377 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=45, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=42.1005859375, floorSegmentMB=1.365234375, forceMergeDeletesPctAllowed=7.950519174065253, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1297640 T5377 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 1297641 T5377 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1297644 T5377 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1297644 T5377 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1297644 T5377 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1297644 T5377 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1297645 T5377 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1297645 T5377 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1297645 T5377 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1297645 T5377 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1297645 T5377 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1297648 T5377 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1297649 T5377 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1297649 T5377 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1297651 T5377 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1297652 T5377 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1297652 T5377 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1297653 T5377 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1297660 T5377 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1297663 T5377 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1297664 T5377 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1297664 T5377 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=44, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1297666 T5377 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1393004299849/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 1297666 T5377 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1297666 T5377 oass.SolrIndexSearcher.<init> Ope
[...truncated too long message...]
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:695)
[junit4] 2> 71) Thread[id=5935, name=Thread-2466-SendThread(localhost:54296), state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
[junit4] 2> 72) Thread[id=5984, name=searcherExecutor-3583-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
[junit4] 2> at java.lang.Thread.run(Thread.java:695)
[junit4] 2> 73) Thread[id=5920, name=Thread-2683, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:485)
[junit4] 2> at org.apache.solr.core.CloserThread.run(CoreContainer.java:1018)
[junit4] 2> 74) Thread[id=5456, name=searcherExecutor-3411-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
[junit4] 2> at java.lang.Thread.run(Thread.java:695)
[junit4] 2> 75) Thread[id=6064, name=coreZkRegister-3605-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
[junit4] 2> at java.lang.Thread.run(Thread.java:695)
[junit4] 2> NOTE: test params are: codec=Lucene46: {id=Pulsing41(freqCutoff=10 minBlockSize=75 maxBlockSize=245), a_t=PostingsFormat(name=Direct), _version_=PostingsFormat(name=Direct), rnd_b=Pulsing41(freqCutoff=10 minBlockSize=75 maxBlockSize=245), a_si=PostingsFormat(name=Asserting)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=es_CL, timezone=America/Bogota
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Apple Inc. 1.6.0_65 (64-bit)/cpus=2,threads=83,free=247519280,total=403898368
[junit4] 2> NOTE: All tests run in this JVM: [TestCharFilters, ChangedSchemaMergeTest, SolrRequestParserTest, TestQueryTypes, TestCSVResponseWriter, CoreAdminCreateDiscoverTest, TestZkChroot, TestFoldingMultitermQuery, MinimalSchemaTest, TestFuzzyAnalyzedSuggestions, TestDocBasedVersionConstraints, TestCodecSupport, TestCoreDiscovery, TestDynamicFieldResource, SolrXmlInZkTest, TestDynamicFieldCollectionResource, XmlUpdateRequestHandlerTest, CSVRequestHandlerTest, DocumentAnalysisRequestHandlerTest, TestFreeTextSuggestions, ShardRoutingCustomTest, ParsingFieldUpdateProcessorsTest, DirectSolrSpellCheckerTest, DistribCursorPagingTest, TestSolrXMLSerializer, TermsComponentTest, MBeansHandlerTest, QueryResultKeyTest, NoCacheHeaderTest, BlockCacheTest, TestUniqueKeyFieldResource, TestSort, FieldAnalysisRequestHandlerTest, SolrIndexConfigTest, SampleTest, TestJoin, JsonLoaderTest, PrimUtilsTest, ClusterStateTest, CustomCollectionTest, SliceStateTest, TestCollationFieldDocValues, SpellingQueryConverterTest, DirectUpdateHandlerOptimizeTest, TestBinaryResponseWriter, OverseerCollectionProcessorTest, TestClassNameShortening, SolrCoreTest, HighlighterConfigTest, TestQuerySenderNoQuery, BasicDistributedZk2Test, TestHighFrequencyDictionaryFactory, TestPhraseSuggestions, TestSolrIndexConfig, FastVectorHighlighterTest, BasicDistributedZkTest, SimpleFacetsTest, TestSolrXmlPersistence, AliasIntegrationTest, JSONWriterTest, SOLR749Test, HdfsBasicDistributedZkTest, TestDocSet, TestSchemaNameResource, TestSchemaVersionResource, TestRecovery, DeleteShardTest, TestPartialUpdateDeduplication, SortByFunctionTest, DateMathParserTest, TestLMJelinekMercerSimilarityFactory, IndexBasedSpellCheckerTest, TestSolrQueryParserResource, RAMDirectoryFactoryTest, DocValuesTest, AssignTest, DistributedDebugComponentTest, TestMergePolicyConfig, SolrPluginUtilsTest, ReturnFieldsTest, TestUtils, TestSystemIdResolver, TestReload, TestPostingsSolrHighlighter, TestArbitraryIndexDir, HdfsLockFactoryTest, TestLuceneMatchVersion, IndexSchemaRuntimeFieldTest, TestQueryUtils, RequiredFieldsTest, TestFiltering, CachingDirectoryFactoryTest, FullSolrCloudDistribCmdsTest, TermVectorComponentTest, SchemaVersionSpecificBehaviorTest, TestSuggestSpellingConverter, TestLMDirichletSimilarityFactory, TestCoreContainer, TestElisionMultitermQuery, NumericFieldsTest, HdfsBasicDistributedZk2Test, PrimitiveFieldTypeTest, TestNumberUtils, TestSolr4Spatial, TestReversedWildcardFilterFactory, AutoCommitTest, TestSolrXml, IndexSchemaTest, SystemInfoHandlerTest, TestReplicationHandler, TestAddFieldRealTimeGet, DocumentBuilderTest, TestJmxMonitoredMap, ResponseLogComponentTest, SolrIndexSplitterTest, TestTrie, TestOverriddenPrefixQueryForCustomFieldType, CoreAdminHandlerTest, SignatureUpdateProcessorFactoryTest, QueryElevationComponentTest, StatsComponentTest, TestXIncludeConfig, TestAnalyzedSuggestions, PingRequestHandlerTest, OutputWriterTest, TestWordDelimiterFilterFactory, TestDistributedSearch, DeleteReplicaTest, HdfsChaosMonkeySafeLeaderTest, TestFastWriter, UpdateRequestProcessorFactoryTest, SolrCoreCheckLockOnStartupTest, TestSerializedLuceneMatchVersion, TriLevelCompositeIdRoutingTest, XsltUpdateRequestHandlerTest, CoreContainerCoreInitFailuresTest, AlternateDirectoryTest, TestSolrJ, LoggingHandlerTest, DirectSolrConnectionTest, QueryParsingTest, TestStressReorder, TestFieldTypeCollectionResource, TestSolrDeletionPolicy1, TestGroupingSearch, TestWriterPerf, FileUtilsTest, TestPHPSerializedResponseWriter, TestCustomSort, AddSchemaFieldsUpdateProcessorFactoryTest, DistributedQueryElevationComponentTest, StandardRequestHandlerTest, TestBadConfig, OverseerTest, SynonymTokenizerTest, DirectUpdateHandlerTest, CopyFieldTest, UniqFieldsUpdateProcessorFactoryTest, PolyFieldTest, DistributedSuggestComponentTest, ScriptEngineTest, TestRemoteStreaming, TestStandardQParsers, DistanceFunctionTest, TestCursorMarkWithoutUniqueKey, OpenExchangeRatesOrgProviderTest, HdfsUnloadDistributedZkTest, TestCloudManagedSchemaAddField, TestCollationKeyRangeQueries, TestInitQParser, ChaosMonkeySafeLeaderTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=B5BEE0A4A7FF4210 -Dtests.slow=true -Dtests.locale=es_CL -Dtests.timezone=America/Bogota -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s | ChaosMonkeySafeLeaderTest (suite) <<<
[junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4] > at __randomizedtesting.SeedInfo.seed([B5BEE0A4A7FF4210]:0)
[junit4] Completed in 7230.74s, 1 test, 2 errors <<< FAILURES!
[...truncated 550 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:459: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:439: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:491: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1272: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:905: There were test failures: 362 suites, 1563 tests, 1 suite-level error, 1 error, 826 ignored (2 assumptions)
Total time: 179 minutes 7 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 1322 -
Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1322/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Wrong doc count on shard1_0 expected:<124> but was:<123>
Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_0 expected:<124> but was:<123>
at __randomizedtesting.SeedInfo.seed([E4F70E40EC0E8E09:651180589B51EE35]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:476)
at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:248)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:112)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:870)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 10287 lines...]
[junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4] 2> 1106660 T3267 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 1106661 T3267 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /o/r
[junit4] 2> 1106667 T3267 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1393033847540
[junit4] 2> 1106668 T3267 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1106669 T3268 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1106779 T3267 oasc.ZkTestServer.run start zk server on port:52049
[junit4] 2> 1106789 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1106794 T3274 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13aa84e8 name:ZooKeeperConnection Watcher:127.0.0.1:52049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1106795 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1106795 T3267 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1106806 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1106810 T3276 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@395b8405 name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1106811 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1106811 T3267 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1106819 T3267 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1106826 T3267 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1106832 T3267 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1106841 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1106842 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1106853 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 1106854 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1106861 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1106862 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1106870 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1106871 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1106878 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1106878 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1106886 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1106887 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1106894 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1106895 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1106902 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1106902 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1106909 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1106909 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1106916 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1106916 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1106924 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1106924 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1107322 T3267 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1107332 T3267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52052
[junit4] 2> 1107335 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1107339 T3267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1107341 T3267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807
[junit4] 2> 1107342 T3267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/'
[junit4] 2> 1107395 T3267 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/solr.xml
[junit4] 2> 1107508 T3267 oasc.CoreContainer.<init> New CoreContainer 233159595
[junit4] 2> 1107508 T3267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/]
[junit4] 2> 1107510 T3267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1107510 T3267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1107511 T3267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1107511 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1107511 T3267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1107511 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1107512 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1107512 T3267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1107512 T3267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1107522 T3267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1107523 T3267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1107523 T3267 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1107524 T3267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52049/solr
[junit4] 2> 1107524 T3267 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1107526 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1107530 T3287 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6583dead name:ZooKeeperConnection Watcher:127.0.0.1:52049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1107530 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1107537 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1107541 T3289 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f56441b name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1107541 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1107546 T3267 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1107556 T3267 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1107568 T3267 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1107574 T3267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52052_o%2Fr
[junit4] 2> 1107577 T3267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52052_o%2Fr
[junit4] 2> 1107587 T3267 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1107593 T3267 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1107604 T3267 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52052_o%2Fr
[junit4] 2> 1107605 T3267 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1107612 T3267 oasc.Overseer.start Overseer (id=91293866232774659-127.0.0.1:52052_o%2Fr-n_0000000000) starting
[junit4] 2> 1107621 T3267 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1107631 T3291 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1107634 T3291 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1107634 T3267 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1107642 T3267 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1107648 T3267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1107656 T3290 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1107663 T3292 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1107663 T3292 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1107666 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1107666 T3292 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1107671 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1107672 T3290 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:52052/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52052_o%2Fr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1107672 T3290 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1107673 T3290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1107679 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1107682 T3289 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> 1108668 T3292 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1108669 T3292 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/collection1
[junit4] 2> 1108670 T3292 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1108673 T3292 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1108673 T3292 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1108678 T3292 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1108678 T3292 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/collection1/'
[junit4] 2> 1108680 T3292 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/collection1/lib/classes/' to classloader
[junit4] 2> 1108680 T3292 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/collection1/lib/README' to classloader
[junit4] 2> 1108761 T3292 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1108820 T3292 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1108824 T3292 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1108833 T3292 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1109364 T3292 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1109367 T3292 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1109369 T3292 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1109376 T3292 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1109437 T3292 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1109438 T3292 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1393033847540/control/data/
[junit4] 2> 1109438 T3292 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@510b6523
[junit4] 2> 1109439 T3292 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/control/data
[junit4] 2> 1109439 T3292 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1393033847540/control/data/index/
[junit4] 2> 1109439 T3292 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1393033847540/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1109439 T3292 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/control/data/index
[junit4] 2> 1109440 T3292 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=21, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1109440 T3292 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7de65357 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a8d808f),segFN=segments_1,generation=1}
[junit4] 2> 1109441 T3292 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1109444 T3292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1109445 T3292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1109445 T3292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1109445 T3292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1109445 T3292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1109446 T3292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1109447 T3292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1109447 T3292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1109448 T3292 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1109448 T3292 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1109449 T3292 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1109449 T3292 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1109450 T3292 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1109450 T3292 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1109450 T3292 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1109451 T3292 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1109463 T3292 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1109470 T3292 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1109472 T3292 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1109472 T3292 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=67.7900390625, floorSegmentMB=0.244140625, forceMergeDeletesPctAllowed=5.25784342504377, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1109473 T3292 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7de65357 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a8d808f),segFN=segments_1,generation=1}
[junit4] 2> 1109473 T3292 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1109473 T3292 oass.SolrIndexSearcher.<init> Opening Searcher@2de2a471[collection1] main
[junit4] 2> 1109480 T3293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2de2a471[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1109481 T3292 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1109483 T3267 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1109483 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1109483 T3296 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52052/o/r collection:control_collection shard:shard1
[junit4] 2> 1109486 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1109487 T3296 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1109489 T3298 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b5c7b7f name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1109490 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1109493 T3267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1109501 T3267 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1109505 T3296 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1109510 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109514 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1109517 T3296 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1109517 T3296 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C698 name=collection1 org.apache.solr.core.SolrCore@5436804a url=http://127.0.0.1:52052/o/r/collection1 node=127.0.0.1:52052_o%2Fr C698_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:52052/o/r, core=collection1, node_name=127.0.0.1:52052_o%2Fr}
[junit4] 2> 1109517 T3296 C698 P52052 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52052/o/r/collection1/
[junit4] 2> 1109517 T3296 C698 P52052 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1109518 T3296 C698 P52052 oasc.SyncStrategy.syncToMe http://127.0.0.1:52052/o/r/collection1/ has no replicas
[junit4] 2> 1109518 T3296 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52052/o/r/collection1/ shard1
[junit4] 2> 1109518 T3296 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1109541 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109545 T3298 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> 1109547 T3289 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> 1109561 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1109576 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109682 T3298 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> 1109683 T3289 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> 1109705 T3296 oasc.ZkController.register We are http://127.0.0.1:52052/o/r/collection1/ and leader is http://127.0.0.1:52052/o/r/collection1/
[junit4] 2> 1109705 T3296 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52052/o/r
[junit4] 2> 1109706 T3296 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1109706 T3296 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1109706 T3296 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1109709 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109709 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109709 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109711 T3296 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1109716 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1109717 T3290 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:52052/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52052_o%2Fr",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1109723 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109828 T3289 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> 1109830 T3298 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> 1109890 T3267 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 1109892 T3267 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1109896 T3267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52056
[junit4] 2> 1109897 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1109897 T3267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1109897 T3267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375
[junit4] 2> 1109898 T3267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/'
[junit4] 2> 1109932 T3267 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/solr.xml
[junit4] 2> 1109998 T3267 oasc.CoreContainer.<init> New CoreContainer 1579081278
[junit4] 2> 1109998 T3267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/]
[junit4] 2> 1109999 T3267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1110000 T3267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1110000 T3267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1110000 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1110000 T3267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1110001 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1110001 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1110001 T3267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1110002 T3267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1110011 T3267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1110011 T3267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1110011 T3267 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1110012 T3267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52049/solr
[junit4] 2> 1110012 T3267 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1110013 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1110018 T3309 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c90e8b8 name:ZooKeeperConnection Watcher:127.0.0.1:52049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1110019 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1110025 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1110030 T3311 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55ab1ae6 name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1110030 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1110049 T3267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1111062 T3267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52056_o%2Fr
[junit4] 2> 1111065 T3267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52056_o%2Fr
[junit4] 2> 1111074 T3298 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1111074 T3311 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1111075 T3289 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1111097 T3312 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1111097 T3312 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1111101 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1111102 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1111102 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1111102 T3312 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1111105 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1111107 T3290 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:52056/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52056_o%2Fr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1111107 T3290 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 1111107 T3290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1111115 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1111226 T3311 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> 1111226 T3298 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> 1111226 T3289 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> 1112104 T3312 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1112104 T3312 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/collection1
[junit4] 2> 1112105 T3312 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1112107 T3312 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1112107 T3312 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1112110 T3312 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1112110 T3312 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/collection1/'
[junit4] 2> 1112112 T3312 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/collection1/lib/classes/' to classloader
[junit4] 2> 1112113 T3312 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/collection1/lib/README' to classloader
[junit4] 2> 1112185 T3312 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1112247 T3312 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1112251 T3312 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1112260 T3312 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1112915 T3312 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1112918 T3312 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1112920 T3312 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1112926 T3312 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1112991 T3312 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1112991 T3312 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty1/
[junit4] 2> 1112991 T3312 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@510b6523
[junit4] 2> 1112992 T3312 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty1
[junit4] 2> 1112992 T3312 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty1/index/
[junit4] 2> 1112992 T3312 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1112993 T3312 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty1/index
[junit4] 2> 1112993 T3312 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=21, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1112994 T3312 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@77d45a42 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5f5e110d),segFN=segments_1,generation=1}
[junit4] 2> 1112994 T3312 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1112999 T3312 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1112999 T3312 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1112999 T3312 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1113000 T3312 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1113000 T3312 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1113000 T3312 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1113001 T3312 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1113001 T3312 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1113001 T3312 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1113002 T3312 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1113003 T3312 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1113003 T3312 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1113003 T3312 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1113004 T3312 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1113004 T3312 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1113005 T3312 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1113014 T3312 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1113019 T3312 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1113019 T3312 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1113020 T3312 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=67.7900390625, floorSegmentMB=0.244140625, forceMergeDeletesPctAllowed=5.25784342504377, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1113020 T3312 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@77d45a42 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5f5e110d),segFN=segments_1,generation=1}
[junit4] 2> 1113021 T3312 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1113021 T3312 oass.SolrIndexSearcher.<init> Opening Searcher@11b6089[collection1] main
[junit4] 2> 1113026 T3313 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@11b6089[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1113029 T3312 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1113031 T3267 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1113031 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1113031 T3316 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52056/o/r collection:collection1 shard:shard2
[junit4] 2> 1113034 T3316 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1113048 T3316 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1113054 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113055 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113055 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113056 T3316 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1113056 T3316 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C699 name=collection1 org.apache.solr.core.SolrCore@4dfdf4bc url=http://127.0.0.1:52056/o/r/collection1 node=127.0.0.1:52056_o%2Fr C699_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:52056/o/r, core=collection1, node_name=127.0.0.1:52056_o%2Fr}
[junit4] 2> 1113056 T3316 C699 P52056 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52056/o/r/collection1/
[junit4] 2> 1113056 T3316 C699 P52056 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1113057 T3316 C699 P52056 oasc.SyncStrategy.syncToMe http://127.0.0.1:52056/o/r/collection1/ has no replicas
[junit4] 2> 1113057 T3316 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52056/o/r/collection1/ shard2
[junit4] 2> 1113057 T3316 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1113064 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1113072 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113073 T3289 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> 1113075 T3311 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> 1113075 T3298 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> 1113091 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1113097 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113204 T3289 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> 1113205 T3298 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> 1113206 T3311 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> 1113239 T3316 oasc.ZkController.register We are http://127.0.0.1:52056/o/r/collection1/ and leader is http://127.0.0.1:52056/o/r/collection1/
[junit4] 2> 1113239 T3316 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52056/o/r
[junit4] 2> 1113240 T3316 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1113240 T3316 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1113240 T3316 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1113244 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113244 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113245 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113251 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1113253 T3316 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1113255 T3290 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:52056/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52056_o%2Fr",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1113264 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113370 T3311 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> 1113372 T3289 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> 1113372 T3298 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> 1113427 T3267 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 1113428 T3267 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1113433 T3267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52059
[junit4] 2> 1113435 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1113435 T3267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1113436 T3267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905
[junit4] 2> 1113436 T3267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/'
[junit4] 2> 1113475 T3267 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/solr.xml
[junit4] 2> 1113554 T3267 oasc.CoreContainer.<init> New CoreContainer 2138793577
[junit4] 2> 1113555 T3267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/]
[junit4] 2> 1113557 T3267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1113557 T3267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1113558 T3267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1113558 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1113558 T3267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1113558 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1113559 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1113559 T3267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1113560 T3267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1113571 T3267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1113572 T3267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1113572 T3267 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1113572 T3267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52049/solr
[junit4] 2> 1113573 T3267 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1113574 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1113579 T3327 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e80b8e1 name:ZooKeeperConnection Watcher:127.0.0.1:52049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1113579 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1113584 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1113589 T3329 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@575d30a0 name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1113590 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1113605 T3267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1114615 T3267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52059_o%2Fr
[junit4] 2> 1114619 T3267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52059_o%2Fr
[junit4] 2> 1114634 T3329 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1114635 T3289 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1114635 T3311 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1114635 T3298 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1114660 T3330 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1114660 T3330 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1114664 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114665 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114665 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114664 T3330 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1114670 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1114672 T3290 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:52059/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52059_o%2Fr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1114673 T3290 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1114673 T3290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1114683 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114795 T3289 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> 1114795 T3298 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> 1114796 T3329 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> 1114796 T3311 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> 1115669 T3330 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1115670 T3330 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/collection1
[junit4] 2> 1115670 T3330 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1115671 T3330 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1115672 T3330 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1115674 T3330 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1115674 T3330 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/collection1/'
[junit4] 2> 1115676 T3330 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/collection1/lib/classes/' to classloader
[junit4] 2> 1115677 T3330 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/collection1/lib/README' to classloader
[junit4] 2> 1115745 T3330 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1115811 T3330 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1115815 T3330 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1115825 T3330 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1116400 T3330 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1116403 T3330 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1116404 T3330 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1116412 T3330 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1116510 T3330 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1116511 T3330 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty2/
[junit4] 2> 1116511 T3330 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@510b6523
[junit4] 2> 1116512 T3330 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty2
[junit4] 2> 1116513 T3330 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty2/index/
[junit4] 2> 1116513 T3330 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1116513 T3330 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty2/index
[junit4] 2> 1116514 T3330 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=21, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1116515 T3330 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71550379 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6086a0c1),segFN=segments_1,generation=1}
[junit4] 2> 1116516 T3330 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1116521 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1116521 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1116522 T3330 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1116522 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1116522 T3330 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1116522 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1116523 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1116524 T3330 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1116524 T3330 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1116525 T3330 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1116526 T3330 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1116526 T3330 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1116527 T3330 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1116528 T3330 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1116528 T3330 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1116530 T3330 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1116540 T3330 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1116544 T3330 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1116545 T3330 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1116546 T3330 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=67.7900390625, floorSegmentMB=0.244140625, forceMergeDeletesPctAllowed=5.25784342504377, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1116546 T3330 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71550379 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6086a0c1),segFN=segments_1,generation=1}
[junit4] 2> 1116546 T3330 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1116547 T3330 oass.SolrIndexSearcher.<init> Opening Searcher@567be7ee[collection1] main
[junit4] 2> 1116551 T3331 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@567be7ee[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1116554 T3330 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1116556 T3267 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1116557 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1116556 T3334 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52059/o/r collection:collection1 shard:shard1
[junit4] 2> 1116560 T3334 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1116577 T3334 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1116585 T3334 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1116585 T3334 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C700 name=collection1 org.apache.solr.core.SolrCore@42ac6287 url=http://127.0.0.1:52059/o/r/collection1 node=127.0.0.1:52059_o%2Fr C700_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:52059/o/r, core=collection1, node_name=127.0.0.1:52059_o%2Fr}
[junit4] 2> 1116586 T3334 C700 P52059 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52059/o/r/collection1/
[junit4] 2> 1116587 T3334 C700 P52059 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1116587 T3334 C700 P52059 oasc.SyncStrategy.syncToMe http://127.0.0.1:52059/o/r/collection1/ has no replicas
[junit4] 2> 1116587 T3334 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52059/o/r/collection1/ shard1
[junit4] 2> 1116588 T3334 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1116589 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116590 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116590 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116597 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116615 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116620 T3311 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> 1116621 T3298 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> 1116621 T3329 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> 1116622 T3289 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> 1116634 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116641 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116747 T3298 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> 1116747 T3289 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> 1116749 T3329 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> 1116752 T3311 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> 1116781 T3334 oasc.ZkController.register We are http://127.0.0.1:52059/o/r/collection1/ and leader is http://127.0.0.1:52059/o/r/collection1/
[junit4] 2> 1116781 T3334 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52059/o/r
[junit4] 2> 1116782 T3334 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1116782 T3334 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1116782 T3334 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1116786 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116786 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116787 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116789 T3334 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116791 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116792 T3290 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:52059/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52059_o%2Fr",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1116804 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116911 T3311 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> 1116912 T3298 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> 1116913 T3289 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> 1116913 T3329 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> 1116937 T3267 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 1116938 T3267 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1116942 T3267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52062
[junit4] 2> 1116943 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1116943 T3267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1116944 T3267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431
[junit4] 2> 1116944 T3267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/'
[junit4] 2> 1116974 T3267 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/solr.xml
[junit4] 2> 1117060 T3267 oasc.CoreContainer.<init> New CoreContainer 804946542
[junit4] 2> 1117060 T3267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/]
[junit4] 2> 1117062 T3267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1117062 T3267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1117063 T3267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1117063 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1117063 T3267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1117063 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1117064 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1117064 T3267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1117064 T3267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1117075 T3267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1117075 T3267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1117076 T3267 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1117076 T3267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52049/solr
[junit4] 2> 1117076 T3267 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1117078 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1117084 T3345 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67891c5d name:ZooKeeperConnection Watcher:127.0.0.1:52049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1117086 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1117093 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1117098 T3347 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f83cbb6 name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1117099 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1117111 T3267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1118126 T3267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52062_o%2Fr
[junit4] 2> 1118128 T3267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52062_o%2Fr
[junit4] 2> 1118143 T3311 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1118144 T3289 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1118145 T3298 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1118145 T3329 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1118145 T3347 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1118176 T3348 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1118177 T3348 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1118183 T3348 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1118183 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1118185 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1118185 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1118193 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1118196 T3290 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:52062/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52062_o%2Fr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1118197 T3290 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1118197 T3290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1118212 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1118320 T3289 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> 1118321 T3298 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> 1118320 T3311 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> 1118320 T3329 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> 1118320 T3347 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> 1119186 T3348 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1119187 T3348 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/collection1
[junit4] 2> 1119187 T3348 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1119190 T3348 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1119190 T3348 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1119194 T3348 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1119195 T3348 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/collection1/'
[junit4] 2> 1119197 T3348 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/collection1/lib/classes/' to classloader
[junit4] 2> 1119197 T3348 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/collection1/lib/README' to classloader
[junit4] 2> 1119259 T3348 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1119315 T3348 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1119319 T3348 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1119327 T3348 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1119859 T3348 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1119864 T3348 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1119867 T3348 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1119874 T3348 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1119945 T3348 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1119946 T3348 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty3/
[junit4] 2> 1119947 T3348 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@510b6523
[junit4] 2> 1119947 T3348 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty3
[junit4] 2> 1119948 T3348 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty3/index/
[junit4] 2> 1119948 T3348 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1119948 T3348 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty3/index
[junit4] 2> 1119949 T3348 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=21, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1119950 T3348 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@62010223 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@315cb70e),segFN=segments_1,generation=1}
[junit4] 2> 1119950 T3348 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1119955 T3348 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1119956 T3348 oasup.UpdateRequestProcessorChain.i
[...truncated too long message...]
b04
[junit4] 2> 1163428 T3366 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=127,cumulative_deletesById=72,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=8084,transaction_logs_total_number=1}
[junit4] 2> 1163430 T3366 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1163430 T3366 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1163430 T3366 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1163432 T3366 oasc.SolrCore.closeSearcher [collection1_shard1_0_replica2] Closing main searcher on request.
[junit4] 2> 1163432 T3366 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1163433 T3366 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data;done=false>>]
[junit4] 2> 1163433 T3366 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data
[junit4] 2> 1163433 T3366 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data/index;done=false>>]
[junit4] 2> 1163434 T3366 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data/index
[junit4] 2> 1163434 T3366 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1_1/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:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[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:254)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1163435 T3366 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/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:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[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:254)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1163435 T3366 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1163436 T3366 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:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[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:254)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=en_IE, timezone=Asia/Kuala_Lumpur
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_51 (64-bit)/cpus=2,threads=1,free=279332824,total=499122176
[junit4] 2> NOTE: All tests run in this JVM: [TestInitQParser, OpenExchangeRatesOrgProviderTest, TestSerializedLuceneMatchVersion, TestRandomMergePolicy, EnumFieldTest, TestFoldingMultitermQuery, TestReplicationHandler, TestStressVersions, TestClassNameShortening, TestSolrJ, TestBlendedInfixSuggestions, CurrencyFieldOpenExchangeTest, CoreContainerCoreInitFailuresTest, UpdateParamsTest, TestLFUCache, BasicZkTest, TestValueSourceCache, TestRecovery, MoreLikeThisHandlerTest, EchoParamsTest, RemoteQueryErrorTest, FieldMutatingUpdateProcessorTest, TestDistributedSearch, LoggingHandlerTest, StressHdfsTest, UUIDFieldTest, SuggesterTest, DirectUpdateHandlerTest, DistributedQueryElevationComponentTest, DistribCursorPagingTest, ZkSolrClientTest, IndexBasedSpellCheckerTest, TestLMJelinekMercerSimilarityFactory, StandardRequestHandlerTest, CoreMergeIndexesAdminHandlerTest, BadIndexSchemaTest, TestSystemIdResolver, DistributedDebugComponentTest, TestAddFieldRealTimeGet, MigrateRouteKeyTest, CollectionsAPIDistributedZkTest, PathHierarchyTokenizerFactoryTest, CopyFieldTest, TestSimpleQParserPlugin, TestSuggestSpellingConverter, HdfsUnloadDistributedZkTest, AutoCommitTest, TestAtomicUpdateErrorCases, LeaderElectionIntegrationTest, MinimalSchemaTest, ZkCLITest, DistributedSpellCheckComponentTest, SolrIndexConfigTest, TestWriterPerf, PreAnalyzedFieldTest, SampleTest, DefaultValueUpdateProcessorTest, TermVectorComponentTest, TestStandardQParsers, BadComponentTest, TestUniqueKeyFieldResource, TestDynamicFieldCollectionResource, ClusterStateTest, TestRealTimeGet, HighlighterConfigTest, ExternalFileFieldSortTest, TestRecoveryHdfs, SuggestComponentTest, NoCacheHeaderTest, CacheHeaderTest, StatsComponentTest, TestSchemaNameResource, TestFieldTypeResource, TestReload, TestHighlightDedupGrouping, TestUtils, UnloadDistributedZkTest, DeleteReplicaTest, HdfsChaosMonkeySafeLeaderTest, TestSolrXMLSerializer, BasicFunctionalityTest, TestPartialUpdateDeduplication, TermVectorComponentDistributedTest, TestJmxIntegration, PeerSyncTest, TestLuceneMatchVersion, ShardSplitTest]
[junit4] Completed in 57.78s, 1 test, 1 failure <<< FAILURES!
[...truncated 845 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:459: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:439: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:499: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1278: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:911: There were test failures: 362 suites, 1563 tests, 1 failure, 41 ignored (7 assumptions)
Total time: 94 minutes 34 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure