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/01/25 09:13:33 UTC

[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.6.0_45) - Build # 9127 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9127/
Java: 32bit/jdk1.6.0_45 -server -XX:+UseConcMarkSweepGC

1 tests failed.
REGRESSION:  org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testDistribSearch

Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:42820/_/zt/collection2, http://127.0.0.1:54310/_/zt/collection2, http://127.0.0.1:57625/_/zt/collection2, http://127.0.0.1:35816/_/zt/collection2, http://127.0.0.1:57340/_/zt/collection2]

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:42820/_/zt/collection2, http://127.0.0.1:54310/_/zt/collection2, http://127.0.0.1:57625/_/zt/collection2, http://127.0.0.1:35816/_/zt/collection2, http://127.0.0.1:57340/_/zt/collection2]
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:352)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:640)
	at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
	at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
	at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testIndexingBatchPerRequestWithHttpSolrServer(FullSolrCloudDistribCmdsTest.java:410)
	at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.doTest(FullSolrCloudDistribCmdsTest.java:143)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	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:662)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: no servers hosting shard: 
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:495)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:317)
	... 46 more




Build Log:
[...truncated 9928 lines...]
   [junit4] Suite: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest
   [junit4]   2> 1043494 T3108 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_/zt
   [junit4]   2> 1043497 T3108 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-FullSolrCloudDistribCmdsTest-1390636924558
   [junit4]   2> 1043497 T3108 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1043498 T3109 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1043598 T3108 oasc.ZkTestServer.run start zk server on port:53087
   [junit4]   2> 1043599 T3108 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1043717 T3115 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fa543d name:ZooKeeperConnection Watcher:127.0.0.1:53087 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1043718 T3108 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1043719 T3108 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1043728 T3108 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1043730 T3117 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@db7b1c name:ZooKeeperConnection Watcher:127.0.0.1:53087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1043731 T3108 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1043732 T3108 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1043740 T3108 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1043748 T3108 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1043754 T3108 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1043762 T3108 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1043763 T3108 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1043775 T3108 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 1043776 T3108 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1043785 T3108 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1043786 T3108 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1043794 T3108 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1043795 T3108 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1043803 T3108 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1043804 T3108 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1043812 T3108 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1043813 T3108 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1043821 T3108 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1043821 T3108 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1043830 T3108 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1043831 T3108 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1043839 T3108 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1043840 T3108 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1043848 T3108 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1043849 T3108 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1043857 T3108 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1043858 T3108 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1043943 T3108 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1043959 T3108 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54310
   [junit4]   2> 1043960 T3108 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1043961 T3108 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1043961 T3108 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1390636924928
   [junit4]   2> 1043961 T3108 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1390636924928/'
   [junit4]   2> 1043974 T3108 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1390636924928/solr.xml
   [junit4]   2> 1044018 T3108 oasc.CoreContainer.<init> New CoreContainer 22892079
   [junit4]   2> 1044019 T3108 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1390636924928/]
   [junit4]   2> 1044020 T3108 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1044020 T3108 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1044020 T3108 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1044021 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1044021 T3108 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1044032 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1044032 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1044033 T3108 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1044033 T3108 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1044035 T3108 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1044035 T3108 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1044035 T3108 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1044036 T3108 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53087/solr
   [junit4]   2> 1044036 T3108 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1044037 T3108 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1044039 T3128 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9dfe8e name:ZooKeeperConnection Watcher:127.0.0.1:53087 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1044040 T3108 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1044045 T3108 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1044047 T3130 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16337b3 name:ZooKeeperConnection Watcher:127.0.0.1:53087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1044047 T3108 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1044050 T3108 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1044057 T3108 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1044067 T3108 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1044072 T3108 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54310__%2Fzt
   [junit4]   2> 1044074 T3108 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54310__%2Fzt
   [junit4]   2> 1044084 T3108 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1044091 T3108 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1044103 T3108 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1044110 T3108 oasc.Overseer.start Overseer (id=91136781488095235-127.0.0.1:54310__%2Fzt-n_0000000000) starting
   [junit4]   2> 1044119 T3108 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1044129 T3132 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1044131 T3108 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1044132 T3132 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 1044139 T3108 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1044145 T3108 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1044154 T3131 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1044160 T3133 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1044160 T3133 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1044164 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1044165 T3133 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1044169 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1044170 T3131 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:54310/_/zt",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:54310__%2Fzt",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1044171 T3131 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1044171 T3131 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1044177 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1044180 T3130 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> 1045165 T3133 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1045166 T3133 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1390636924928/collection1
   [junit4]   2> 1045166 T3133 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1045168 T3133 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1045168 T3133 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1045171 T3133 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1390636924928/collection1/'
   [junit4]   2> 1045173 T3133 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1390636924928/collection1/lib/classes/' to classloader
   [junit4]   2> 1045173 T3133 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1390636924928/collection1/lib/README' to classloader
   [junit4]   2> 1045240 T3133 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 1045296 T3133 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1045299 T3133 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1045304 T3133 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1045785 T3133 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1045788 T3133 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1045789 T3133 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1045793 T3133 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1045829 T3133 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1045830 T3133 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1390636924928/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/control/data/
   [junit4]   2> 1045830 T3133 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@152cfbb
   [junit4]   2> 1045831 T3133 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/control/data
   [junit4]   2> 1045831 T3133 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/control/data/index/
   [junit4]   2> 1045832 T3133 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1045832 T3133 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/control/data/index
   [junit4]   2> 1045833 T3133 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=6, maxMergeAtOnceExplicit=7, maxMergedSegmentMB=68.685546875, floorSegmentMB=2.0234375, forceMergeDeletesPctAllowed=14.15640641249581, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3095842667810855
   [junit4]   2> 1045833 T3133 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1adaaee lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b10295),segFN=segments_1,generation=1}
   [junit4]   2> 1045834 T3133 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1045838 T3133 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1045838 T3133 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1045838 T3133 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1045839 T3133 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1045839 T3133 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1045839 T3133 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1045840 T3133 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1045840 T3133 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1045841 T3133 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1045841 T3133 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1045842 T3133 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1045842 T3133 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1045842 T3133 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1045843 T3133 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1045843 T3133 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1045844 T3133 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1045846 T3133 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1045849 T3133 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1045850 T3133 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1045865 T3133 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=84.296875, floorSegmentMB=1.0986328125, forceMergeDeletesPctAllowed=22.807041003638226, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2697450852456704
   [junit4]   2> 1045866 T3133 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1adaaee lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b10295),segFN=segments_1,generation=1}
   [junit4]   2> 1045866 T3133 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1045866 T3133 oass.SolrIndexSearcher.<init> Opening Searcher@1e148be main
   [junit4]   2> 1045869 T3134 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e148be main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1045871 T3133 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1045872 T3108 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1045872 T3108 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1045872 T3137 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54310/_/zt collection:control_collection shard:shard1
   [junit4]   2> 1045873 T3108 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1045875 T3139 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@125fe39 name:ZooKeeperConnection Watcher:127.0.0.1:53087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1045875 T3108 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1045875 T3137 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1045878 T3108 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1045884 T3108 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1045891 T3137 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1045895 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1045897 T3137 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1045898 T3137 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C6205 name=collection1 org.apache.solr.core.SolrCore@12a454b url=http://127.0.0.1:54310/_/zt/collection1 node=127.0.0.1:54310__%2Fzt C6205_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:54310/_/zt, core=collection1, node_name=127.0.0.1:54310__%2Fzt}
   [junit4]   2> 1045898 T3137 C6205 P54310 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54310/_/zt/collection1/
   [junit4]   2> 1045898 T3137 C6205 P54310 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1045898 T3137 C6205 P54310 oasc.SyncStrategy.syncToMe http://127.0.0.1:54310/_/zt/collection1/ has no replicas
   [junit4]   2> 1045898 T3137 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54310/_/zt/collection1/ shard1
   [junit4]   2> 1045898 T3137 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1045901 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1045906 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1045907 T3139 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> 1045908 T3130 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> 1045915 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1045960 T3108 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1045961 T3108 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1045964 T3108 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33633
   [junit4]   2> 1045966 T3108 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1045966 T3108 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1045967 T3108 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1390636926946
   [junit4]   2> 1045968 T3108 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1390636926946/'
   [junit4]   2> 1045994 T3108 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1390636926946/solr.xml
   [junit4]   2> 1045994 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1046048 T3108 oasc.CoreContainer.<init> New CoreContainer 25975231
   [junit4]   2> 1046049 T3108 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1390636926946/]
   [junit4]   2> 1046050 T3108 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1046050 T3108 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1046051 T3108 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1046051 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1046052 T3108 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1046052 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1046053 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1046053 T3108 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1046053 T3108 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1046055 T3108 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1046056 T3108 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1046056 T3108 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1046056 T3108 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53087/solr
   [junit4]   2> 1046057 T3108 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1046058 T3108 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1046059 T3150 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15847ea name:ZooKeeperConnection Watcher:127.0.0.1:53087 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1046060 T3108 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1046065 T3108 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1046066 T3152 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e18667 name:ZooKeeperConnection Watcher:127.0.0.1:53087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1046066 T3108 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1046075 T3108 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1046098 T3130 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> 1046098 T3139 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> 1046098 T3152 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> 1046112 T3137 oasc.ZkController.register We are http://127.0.0.1:54310/_/zt/collection1/ and leader is http://127.0.0.1:54310/_/zt/collection1/
   [junit4]   2> 1046112 T3137 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54310/_/zt
   [junit4]   2> 1046113 T3137 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1046113 T3137 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1046113 T3137 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1046115 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1046116 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1046116 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1046119 T3137 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1046122 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1046124 T3131 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:54310/_/zt",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:54310__%2Fzt",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1046130 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1046235 T3130 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> 1046235 T3139 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> 1046251 T3152 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> 1047084 T3108 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33633__%2Fzt
   [junit4]   2> 1047087 T3108 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33633__%2Fzt
   [junit4]   2> 1047096 T3130 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1047097 T3139 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1047097 T3152 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1047114 T3153 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1047115 T3153 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1047117 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1047117 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1047117 T3153 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1047118 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1047121 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1047123 T3131 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:33633/_/zt",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:33633__%2Fzt",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1047124 T3131 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 1047124 T3131 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1047131 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1047236 T3130 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> 1047237 T3139 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> 1047237 T3152 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> 1048119 T3153 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1048119 T3153 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1390636926946/collection1
   [junit4]   2> 1048119 T3153 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1048121 T3153 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1048121 T3153 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1048124 T3153 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1390636926946/collection1/'
   [junit4]   2> 1048125 T3153 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1390636926946/collection1/lib/classes/' to classloader
   [junit4]   2> 1048125 T3153 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1390636926946/collection1/lib/README' to classloader
   [junit4]   2> 1048179 T3153 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 1048240 T3153 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1048242 T3153 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1048247 T3153 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1048746 T3153 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1048748 T3153 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1048750 T3153 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1048754 T3153 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1048803 T3153 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1048803 T3153 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1390636926946/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/jetty1/
   [junit4]   2> 1048804 T3153 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@152cfbb
   [junit4]   2> 1048805 T3153 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/jetty1
   [junit4]   2> 1048805 T3153 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/jetty1/index/
   [junit4]   2> 1048806 T3153 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1048807 T3153 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/jetty1/index
   [junit4]   2> 1048808 T3153 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=6, maxMergeAtOnceExplicit=7, maxMergedSegmentMB=68.685546875, floorSegmentMB=2.0234375, forceMergeDeletesPctAllowed=14.15640641249581, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3095842667810855
   [junit4]   2> 1048809 T3153 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1b86f4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@192dc2d),segFN=segments_1,generation=1}
   [junit4]   2> 1048809 T3153 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1048816 T3153 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1048816 T3153 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1048817 T3153 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1048817 T3153 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1048817 T3153 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1048817 T3153 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1048818 T3153 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1048818 T3153 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1048818 T3153 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1048819 T3153 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1048819 T3153 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1048819 T3153 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1048820 T3153 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1048820 T3153 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1048820 T3153 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1048821 T3153 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1048823 T3153 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1048825 T3153 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1048825 T3153 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1048826 T3153 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=84.296875, floorSegmentMB=1.0986328125, forceMergeDeletesPctAllowed=22.807041003638226, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2697450852456704
   [junit4]   2> 1048826 T3153 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1b86f4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@192dc2d),segFN=segments_1,generation=1}
   [junit4]   2> 1048826 T3153 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1048827 T3153 oass.SolrIndexSearcher.<init> Opening Searcher@164c95a main
   [junit4]   2> 1048839 T3154 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@164c95a main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1048841 T3153 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1048842 T3108 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1048843 T3108 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1048842 T3157 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33633/_/zt collection:collection1 shard:shard1
   [junit4]   2> 1048845 T3157 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1048858 T3157 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1048860 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1048861 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1048861 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1048862 T3157 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1048862 T3157 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C6206 name=collection1 org.apache.solr.core.SolrCore@122aff4 url=http://127.0.0.1:33633/_/zt/collection1 node=127.0.0.1:33633__%2Fzt C6206_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:33633/_/zt, core=collection1, node_name=127.0.0.1:33633__%2Fzt}
   [junit4]   2> 1048862 T3157 C6206 P33633 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33633/_/zt/collection1/
   [junit4]   2> 1048863 T3157 C6206 P33633 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1048863 T3157 C6206 P33633 oasc.SyncStrategy.syncToMe http://127.0.0.1:33633/_/zt/collection1/ has no replicas
   [junit4]   2> 1048863 T3157 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33633/_/zt/collection1/ shard1
   [junit4]   2> 1048863 T3157 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1048864 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1048872 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1048875 T3139 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> 1048875 T3152 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> 1048875 T3130 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> 1048885 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1048888 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1048914 T3108 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1048915 T3108 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1048918 T3108 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35816
   [junit4]   2> 1048919 T3108 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1048920 T3108 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1048921 T3108 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1390636929905
   [junit4]   2> 1048921 T3108 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1390636929905/'
   [junit4]   2> 1048951 T3108 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1390636929905/solr.xml
   [junit4]   2> 1048991 T3139 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> 1048992 T3130 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> 1048992 T3152 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> 1049007 T3108 oasc.CoreContainer.<init> New CoreContainer 17342416
   [junit4]   2> 1049008 T3108 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1390636929905/]
   [junit4]   2> 1049009 T3108 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1049009 T3108 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1049010 T3108 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1049010 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1049010 T3108 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1049011 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1049011 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1049011 T3108 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1049012 T3108 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1049014 T3108 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1049014 T3108 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1049014 T3108 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1049015 T3108 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53087/solr
   [junit4]   2> 1049015 T3108 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1049016 T3108 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1049018 T3168 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1053e93 name:ZooKeeperConnection Watcher:127.0.0.1:53087 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1049019 T3108 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1049021 T3108 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1049023 T3170 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1267081 name:ZooKeeperConnection Watcher:127.0.0.1:53087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1049023 T3108 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1049028 T3108 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1049039 T3157 oasc.ZkController.register We are http://127.0.0.1:33633/_/zt/collection1/ and leader is http://127.0.0.1:33633/_/zt/collection1/
   [junit4]   2> 1049040 T3157 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33633/_/zt
   [junit4]   2> 1049040 T3157 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1049040 T3157 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1049040 T3157 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1049042 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1049042 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1049042 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1049043 T3157 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1049046 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1049047 T3131 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:33633/_/zt",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:33633__%2Fzt",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1049051 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1049165 T3152 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> 1049165 T3139 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> 1049166 T3170 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> 1049165 T3130 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> 1050033 T3108 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35816__%2Fzt
   [junit4]   2> 1050035 T3108 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35816__%2Fzt
   [junit4]   2> 1050040 T3139 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1050040 T3130 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1050041 T3152 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1050041 T3170 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1050058 T3171 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1050059 T3171 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1050061 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1050061 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1050061 T3171 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1050062 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1050064 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1050066 T3131 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:35816/_/zt",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:35816__%2Fzt",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1050066 T3131 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1050066 T3131 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1050072 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1050176 T3152 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> 1050177 T3139 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> 1050176 T3130 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> 1050177 T3170 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> 1051062 T3171 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1051063 T3171 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1390636929905/collection1
   [junit4]   2> 1051063 T3171 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1051065 T3171 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1051065 T3171 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1051068 T3171 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1390636929905/collection1/'
   [junit4]   2> 1051069 T3171 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1390636929905/collection1/lib/classes/' to classloader
   [junit4]   2> 1051070 T3171 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1390636929905/collection1/lib/README' to classloader
   [junit4]   2> 1051120 T3171 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 1051184 T3171 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1051187 T3171 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1051192 T3171 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1051708 T3171 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1051711 T3171 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1051713 T3171 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1051717 T3171 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1051764 T3171 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1051764 T3171 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1390636929905/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/jetty2/
   [junit4]   2> 1051764 T3171 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@152cfbb
   [junit4]   2> 1051765 T3171 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/jetty2
   [junit4]   2> 1051765 T3171 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/jetty2/index/
   [junit4]   2> 1051765 T3171 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1051766 T3171 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1390636924558/jetty2/index
   [junit4]   2> 1051766 T3171 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=6, maxMergeAtOnceExplicit=7, maxMergedSegmentMB=68.685546875, floorSegmentMB=2.0234375, forceMergeDeletesPctAllowed=14.15640641249581, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3095842667810855
   [junit4]   2> 1051767 T3171 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@19d1179 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e65206),segFN=segments_1,generation=1}
   [junit4]   2> 1051767 T3171 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1051771 T3171 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1051772 T3171 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1051772 T3171 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1051772 T3171 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1051773 T3171 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1051773 T3171 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1051773 T3171 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1051774 T3171 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1051774 T3171 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1051775 T3171 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1051775 T3171 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1051775 T3171 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1051776 T3171 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1051776 T3171 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1051777 T3171 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1051778 T3171 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1051780 T3171 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1051782 T3171 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1051782 T3171 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1051783 T3171 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=84.296875, floorSegmentMB=1.0986328125, forceMergeDeletesPctAllowed=22.807041003638226, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2697450852456704
   [junit4]   2> 1051783 T3171 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@19d1179 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e65206),segFN=segments_1,generation=1}
   [junit4]   2> 1051783 T3171 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1051784 T3171 oass.SolrIndexSearcher.<init> Opening Searcher@1199003 main
   [junit4]   2> 1051796 T3172 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1199003 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1051797 T3171 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1051798 T3108 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1051799 T3108 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1051798 T3175 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35816/_/zt collection:collection1 shard:shard2
   [junit4]   2> 1051801 T3175 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1051809 T3175 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1051875 T3108 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 1051875 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1051875 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1051876 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1051876 T3108 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1051876 T3175 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1051877 T3175 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C6207 name=collection1 org.apache.solr.core.SolrCore@10515f9 url=http://127.0.0.1:35816/_/zt/collection1 node=127.0.0.1:35816__%2Fzt C6207_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:35816/_/zt, core=collection1, node_name=127.0.0.1:35816__%2Fzt}
   [junit4]   2> 1051877 T3175 C6207 P35816 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35816/_/zt/collection1/
   [junit4]   2> 1051877 T3175 C6207 P35816 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1051878 T3175 C6207 P35816 oasc.SyncStrategy.syncToMe http://127.0.0.1:35816/_/zt/collection1/ has no replicas
   [junit4]   2> 1051878 T3175 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35816/_/zt/collection1/ shard2
   [junit4]   2> 1051879 T3175 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1051879 T3108 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57625
   [junit4]   2> 1051880 T3108 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1051881 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1051881 T3108 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1051882 T3108 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1390636932860
   [junit4]   2> 1051883 T3108 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1390636932860/'
   [junit4]   2> 1051893 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1051895 T3152 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> 1051895 T3130 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> 1051895 T3139 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> 1051896 T3170 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> 1051906 T3108 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1390636932860/solr.xml
   [junit4]   2> 1051906 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1051922 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1051967 T3108 oasc.CoreContainer.<init> New CoreContainer 12124279
   [junit4]   2> 1051967 T3108 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1390636932860/]
   [junit4]   2> 1051969 T3108 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1051969 T3108 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1051969 T3108 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1051970 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1051970 T3108 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1051970 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1051971 T3108 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1051971 T3108 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1051971 T3108 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1051973 T3108 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1051974 T3108 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1051974 T3108 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1051974 T3108 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53087/solr
   [junit4]   2> 1051975 T3108 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1051976 T3108 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1051977 T3186 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cdbc64 name:ZooKeeperConnection Watcher:127.0.0.1:53087 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1051977 T3108 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1051980 T3108 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1051981 T3188 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10af23e name:ZooKeeperConnection Watcher:127.0.0.1:53087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1051981 T3108 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1051988 T3108 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1052028 T3152 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> 1052028 T3139 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> 1052029 T3188 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> 1052029 T3170 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> 1052029 T3130 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> 1052055 T3175 oasc.ZkController.register We are http://127.0.0.1:35816/_/zt/collection1/ and leader is http://127.0.0.1:35816/_/zt/collection1/
   [junit4]   2> 1052055 T3175 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35816/_/zt
   [junit4]   2> 1052055 T3175 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1052056 T3175 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1052056 T3175 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1052058 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1052059 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1052059 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1052061 T3175 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1052065 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1052067 T3131 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:35816/_/zt",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:35816__%2Fzt",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1052074 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1052178 T3152 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> 1052178 T3130 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> 1052178 T3139 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> 1052179 T3170 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> 1052179 T3188 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> 1052994 T3108 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57625__%2Fzt
   [junit4]   2> 1052997 T3108 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57625__%2Fzt
   [junit4]   2> 1053002 T3130 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1053003 T3139 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1053003 T3152 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1053004 T3170 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1053004 T3188 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1053013 T3189 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1053013 T3189 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1053015 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1053016 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1053016 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1053016 T3189 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1053019 T3131 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1053020 T3131 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:57625/_/zt",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57625__%2Fzt",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1053020 T3131 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1053020 T3131 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 1053060 T3130 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1053164 T3152 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> 1053164 T3139 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> 1053164 T3130 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> 1053165 T3170 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> 1053164 T3188 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> 1054017 T3189 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1054017 T3189 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1390636932860/collection1
   [junit4]   2> 1054017 T3189 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1054018 T3189 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1054019 T3189 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1054020 T3189 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1390636932860/collection1/'
   [junit4]   2> 1054021 T3189 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1390636932860/collection1/lib/classes/' to classloader
   [junit4]   2> 1054021 T3189 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1390636932860/collection1/lib/README' to classloader
   [junit4]   2> 1054071 T3189 oasc.SolrConfig.

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

tryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java: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> 1151495 T3245 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection2/leader_elect/shard28/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java: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> 1151495 T3245 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java: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> 1151495 T3245 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection2/leader_elect/shard8/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java: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> 1151496 T3245 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection2/leader_elect/shard13/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java: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=Lucene45, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=en_AU, timezone=Indian/Antananarivo
   [junit4]   2> NOTE: Linux 3.8.0-35-generic i386/Sun Microsystems Inc. 1.6.0_45 (32-bit)/cpus=8,threads=1,free=190905200,total=484900864
   [junit4]   2> NOTE: All tests run in this JVM: [FieldAnalysisRequestHandlerTest, SortByFunctionTest, StandardRequestHandlerTest, SolrCoreCheckLockOnStartupTest, IndexSchemaRuntimeFieldTest, TestQueryTypes, TestIBSimilarityFactory, TestWordDelimiterFilterFactory, ConvertedLegacyTest, TestCollationField, TestFiltering, XsltUpdateRequestHandlerTest, TestStressRecovery, BasicZkTest, BlockDirectoryTest, TestFoldingMultitermQuery, SpellCheckComponentTest, TestCollationKeyRangeQueries, ChaosMonkeyNothingIsSafeTest, TestCustomSort, CachingDirectoryFactoryTest, RAMDirectoryFactoryTest, TestQuerySenderListener, TestDefaultSearchFieldResource, XmlUpdateRequestHandlerTest, TestUtils, MigrateRouteKeyTest, HardAutoCommitTest, NoCacheHeaderTest, HighlighterTest, TestImplicitCoreProperties, TestCSVResponseWriter, StatsComponentTest, NumericFieldsTest, TestDistribDocBasedVersion, TestCoreDiscovery, AliasIntegrationTest, HighlighterConfigTest, TestCloudManagedSchemaAddField, ShardRoutingCustomTest, SolrCmdDistributorTest, SolrRequestParserTest, UniqFieldsUpdateProcessorFactoryTest, AlternateDirectoryTest, DefaultValueUpdateProcessorTest, TestNumberUtils, DirectSolrSpellCheckerTest, BadIndexSchemaTest, HdfsSyncSliceTest, TestRecovery, TestSolrJ, OpenCloseCoreStressTest, SuggesterTSTTest, FileUtilsTest, TestDistributedGrouping, HdfsDirectoryTest, TestSolrQueryParserDefaultOperatorResource, MinimalSchemaTest, HdfsUnloadDistributedZkTest, TestDefaultSimilarityFactory, TestSchemaSimilarityResource, DirectUpdateHandlerTest, TermVectorComponentDistributedTest, TestFileDictionaryLookup, TestPartialUpdateDeduplication, TestRangeQuery, TestCursorMarkWithoutUniqueKey, AddBlockUpdateTest, TestUpdate, TestCodecSupport, ZkNodePropsTest, TestRandomFaceting, CurrencyFieldOpenExchangeTest, HdfsChaosMonkeySafeLeaderTest, ShardSplitTest, PathHierarchyTokenizerFactoryTest, MultiTermTest, TestComponentsName, DocumentAnalysisRequestHandlerTest, StressHdfsTest, HdfsBasicDistributedZkTest, BasicDistributedZk2Test, TestFreeTextSuggestions, DirectSolrConnectionTest, TestFieldResource, TestDynamicFieldCollectionResource, TestFieldTypeResource, OverseerTest, LeaderElectionIntegrationTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest]
   [junit4] Completed on J1 in 108.43s, 1 test, 1 error <<< FAILURES!

[...truncated 516 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:439: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1308: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:941: There were test failures: 355 suites, 1547 tests, 1 error, 35 ignored (7 assumptions)

Total time: 60 minutes 27 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.6.0_45 -server -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



[JENKINS] Lucene-Solr-4.x-Linux (64bit/ibm-j9-jdk7) - Build # 9128 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9128/
Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}

2 tests failed.
REGRESSION:  org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testMultiThreaded

Error Message:
expected:<1> but was:<2>

Stack Trace:
java.lang.AssertionError: expected:<1> but was:<2>
	at __randomizedtesting.SeedInfo.seed([D0E2D4BE718E1C9B:B1770E5E995F166D]: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.junit.Assert.assertEquals(Assert.java:456)
	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.checkNumDocs(SignatureUpdateProcessorFactoryTest.java:71)
	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testMultiThreaded(SignatureUpdateProcessorFactoryTest.java:222)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	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:780)


REGRESSION:  org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testDupeDetection

Error Message:
expected:<1> but was:<3>

Stack Trace:
java.lang.AssertionError: expected:<1> but was:<3>
	at __randomizedtesting.SeedInfo.seed([D0E2D4BE718E1C9B:8BD22F7672C9BFE7]: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.junit.Assert.assertEquals(Assert.java:456)
	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.checkNumDocs(SignatureUpdateProcessorFactoryTest.java:71)
	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testDupeDetection(SignatureUpdateProcessorFactoryTest.java:119)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	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:780)




Build Log:
[...truncated 10558 lines...]
   [junit4] Suite: org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest
   [junit4]   2> 560392 T2420 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808
   [junit4]   2> 560392 T2420 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/'
   [junit4]   2> 560393 T2420 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 560393 T2420 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 560440 T2420 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 560499 T2420 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 560499 T2420 oass.IndexSchema.readSchema Reading Solr Schema from schema12.xml
   [junit4]   2> 560505 T2420 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 560864 T2420 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 560867 T2420 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 560868 T2420 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (2)
   [junit4]   2> 560873 T2420 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 560877 T2420 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 560880 T2420 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 560881 T2420 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr
   [junit4]   2> 560881 T2420 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/'
   [junit4]   2> 560887 T2420 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 560888 T2420 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr
   [junit4]   2> 560888 T2420 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/'
   [junit4]   2> 560924 T2420 oasc.CoreContainer.<init> New CoreContainer 1381416246
   [junit4]   2> 560925 T2420 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/]
   [junit4]   2> 560926 T2420 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 560926 T2420 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 560926 T2420 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 560927 T2420 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 560927 T2420 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 560927 T2420 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 560928 T2420 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 560928 T2420 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 560928 T2420 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 560931 T2420 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 560931 T2420 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 560932 T2420 oasc.CoreContainer.load Host Name: 
   [junit4]   2> 560935 T2421 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1
   [junit4]   2> 560935 T2421 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/'
   [junit4]   2> 560935 T2421 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 560936 T2421 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 560968 T2421 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 561012 T2421 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 561013 T2421 oass.IndexSchema.readSchema Reading Solr Schema from schema12.xml
   [junit4]   2> 561018 T2421 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 561300 T2421 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 561302 T2421 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 561304 T2421 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (2)
   [junit4]   2> 561308 T2421 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 561312 T2421 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 561315 T2421 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 561315 T2421 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808/
   [junit4]   2> 561315 T2421 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a6ae1304
   [junit4]   2> 561316 T2421 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808
   [junit4]   2> 561316 T2421 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808/index/
   [junit4]   2> 561317 T2421 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808/index' doesn't exist. Creating new index...
   [junit4]   2> 561317 T2421 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808/index
   [junit4]   2> 561318 T2421 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=45, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.19577976551494905]
   [junit4]   2> 561318 T2421 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_1,generation=1}
   [junit4]   2> 561318 T2421 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 561319 T2421 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 561321 T2421 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 561321 T2421 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 561321 T2421 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 561321 T2421 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 561322 T2421 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 561322 T2421 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 561322 T2421 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 561323 T2421 oasup.UniqFieldsUpdateProcessorFactory.init WARN Use of the 'fields' init param in UniqFieldsUpdateProcessorFactory is deprecated, please use 'fieldName' (or another FieldMutatingUpdateProcessorFactory selector option) instead
   [junit4]   2> 561323 T2421 oasup.UniqFieldsUpdateProcessorFactory.init Replacing 'fields' init param with (individual) 'fieldName' params
   [junit4]   2> 561323 T2421 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 561324 T2421 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 561324 T2421 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 561324 T2421 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 561325 T2421 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 561325 T2421 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 561326 T2421 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 561326 T2421 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 561327 T2421 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 561327 T2421 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 561328 T2421 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 561329 T2421 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 561329 T2421 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 561330 T2421 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 561330 T2421 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 561331 T2421 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 561331 T2421 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 561332 T2421 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 561332 T2421 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 561333 T2421 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 561334 T2421 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 561334 T2421 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 561335 T2421 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 561335 T2421 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 561336 T2421 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 561337 T2421 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
   [junit4]   2> 561337 T2421 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 561339 T2421 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 561341 T2421 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 561344 T2421 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 561344 T2421 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 561345 T2421 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.26059076597918046]
   [junit4]   2> 561345 T2421 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_1,generation=1}
   [junit4]   2> 561346 T2421 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 561346 T2421 oass.SolrIndexSearcher.<init> Opening Searcher@b23e6346 main
   [junit4]   2> 561346 T2421 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 561407 T2421 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 561426 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b23e6346 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 561430 T2421 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 561432 T2420 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 561435 T2420 oas.SolrTestCaseJ4.setUp ###Starting testNonStringFieldsValues
   [junit4]   2> ASYNC  NEW_CORE C1127 name=collection1 org.apache.solr.core.SolrCore@d78ee463
   [junit4]   2> 561435 T2420 C1127 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 561436 T2420 C1127 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 561439 T2420 C1127 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561440 T2420 C1127 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_2,generation=2}
   [junit4]   2> 561441 T2420 C1127 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 561441 T2420 C1127 oass.SolrIndexSearcher.<init> Opening Searcher@9ac61245 main
   [junit4]   2> 561442 T2420 C1127 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561443 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9ac61245 main{StandardDirectoryReader(segments_2:2:nrt)}
   [junit4]   2> 561444 T2420 C1127 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 561446 T2420 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 561507 T2420 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561509 T2420 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_3,generation=3}
   [junit4]   2> 561510 T2420 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 561511 T2420 oass.SolrIndexSearcher.<init> Opening Searcher@55126bc0 main
   [junit4]   2> 561512 T2420 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561513 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@55126bc0 main{StandardDirectoryReader(segments_3:4:nrt _0(4.7):c5/1:delGen=1)}
   [junit4]   2> 561514 T2420 oas.SolrTestCaseJ4.tearDown ###Ending testNonStringFieldsValues
   [junit4]   2> 561517 T2420 oas.SolrTestCaseJ4.setUp ###Starting testFailNonIndexedSigWithOverwriteDupes
   [junit4]   2> 561518 T2420 C1127 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 561518 T2420 C1127 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 0
   [junit4]   2> 561559 T2420 C1127 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561559 T2420 C1127 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_4,generation=4}
   [junit4]   2> 561560 T2420 C1127 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 561561 T2420 C1127 oass.SolrIndexSearcher.<init> Opening Searcher@370e02ad main
   [junit4]   2> 561561 T2420 C1127 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561563 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@370e02ad main{StandardDirectoryReader(segments_4:5:nrt)}
   [junit4]   2> 561575 T2420 C1127 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 16
   [junit4]   2> 561577 T2420 oas.SolrTestCaseJ4.tearDown ###Ending testFailNonIndexedSigWithOverwriteDupes
   [junit4]   2> 561580 T2420 oas.SolrTestCaseJ4.setUp ###Starting testNonIndexedSignatureField
   [junit4]   2> 561581 T2420 C1127 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 561582 T2420 C1127 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 561583 T2420 C1127 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561583 T2420 C1127 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_5,generation=5}
   [junit4]   2> 561584 T2420 C1127 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 561585 T2420 C1127 oass.SolrIndexSearcher.<init> Opening Searcher@5a6687e5 main
   [junit4]   2> 561585 T2420 C1127 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561586 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5a6687e5 main{StandardDirectoryReader(segments_5:6:nrt)}
   [junit4]   2> 561587 T2420 C1127 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 561593 T2420 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561594 T2420 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_5,generation=5}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_6,generation=6}
   [junit4]   2> 561595 T2420 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
   [junit4]   2> 561596 T2420 oass.SolrIndexSearcher.<init> Opening Searcher@3a659623 main
   [junit4]   2> 561596 T2420 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561598 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3a659623 main{StandardDirectoryReader(segments_6:8:nrt _1(4.7):c2)}
   [junit4]   2> 561598 T2420 oas.SolrTestCaseJ4.tearDown ###Ending testNonIndexedSignatureField
   [junit4]   2> 561601 T2420 oas.SolrTestCaseJ4.setUp ###Starting testMultiThreaded
   [junit4]   2> 561602 T2420 C1127 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 561602 T2420 C1127 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 0
   [junit4]   2> 561604 T2420 C1127 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561604 T2420 C1127 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_6,generation=6}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_7,generation=7}
   [junit4]   2> 561605 T2420 C1127 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 7
   [junit4]   2> 561606 T2420 C1127 oass.SolrIndexSearcher.<init> Opening Searcher@a5126522 main
   [junit4]   2> 561606 T2420 C1127 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561607 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a5126522 main{StandardDirectoryReader(segments_7:9:nrt)}
   [junit4]   2> 561608 T2420 C1127 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 561620 T2432 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561643 T2432 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_7,generation=7}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_8,generation=8}
   [junit4]   2> 561645 T2432 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 8
   [junit4]   2> 561748 T2432 oass.SolrIndexSearcher.<init> Opening Searcher@921d8e2c main
   [junit4]   2> 561748 T2432 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561749 T2433 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561750 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@921d8e2c main{StandardDirectoryReader(segments_8:16:nrt _3(4.7):c63/59:delGen=1)}
   [junit4]   2> 561913 T2433 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_8,generation=8}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_9,generation=9}
   [junit4]   2> 561913 T2433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 9
   [junit4]   2> 561917 T2433 oass.SolrIndexSearcher.<init> Opening Searcher@6a76f924 main
   [junit4]   2> 561917 T2433 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561918 T2431 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561918 T2431 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_9,generation=9}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_a,generation=10}
   [junit4]   2> 561919 T2431 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 10
   [junit4]   2> 561918 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6a76f924 main{StandardDirectoryReader(segments_9:21:nrt _4(4.7):c137/134:delGen=2 _5(4.7):c1)}
   [junit4]   2> 561920 T2431 oass.SolrIndexSearcher.<init> Opening Searcher@6b738374 main
   [junit4]   2> 561921 T2431 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561921 T2432 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561922 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6b738374 main{StandardDirectoryReader(segments_9:21:nrt _4(4.7):c137/134:delGen=2 _5(4.7):c1)}
   [junit4]   2> 561923 T2432 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_a,generation=10}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_b,generation=11}
   [junit4]   2> 561924 T2432 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 11
   [junit4]   2> 561932 T2432 oass.SolrIndexSearcher.<init> Opening Searcher@c5eea99 main
   [junit4]   2> 561933 T2432 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561933 T2433 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561946 T2433 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_b,generation=11}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_c,generation=12}
   [junit4]   2> 561947 T2433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 12
   [junit4]   2> 561947 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c5eea99 main{StandardDirectoryReader(segments_b:28:nrt _4(4.7):c137/135:delGen=3 _7(4.7):c1)}
   [junit4]   2> 561948 T2433 oass.SolrIndexSearcher.<init> Opening Searcher@c0833704 main
   [junit4]   2> 561948 T2433 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561949 T2431 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561949 T2431 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 561950 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c0833704 main{StandardDirectoryReader(segments_b:28:nrt _4(4.7):c137/135:delGen=3 _7(4.7):c1)}
   [junit4]   2> 561957 T2431 oass.SolrIndexSearcher.<init> Opening Searcher@dac7d019 main
   [junit4]   2> 561957 T2431 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561957 T2432 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561959 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@dac7d019 main{StandardDirectoryReader(segments_c:32:nrt _4(4.7):c137/136:delGen=3 _7(4.7):c1 _8(4.7):c1)}
   [junit4]   2> 561964 T2432 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_c,generation=12}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_d,generation=13}
   [junit4]   2> 561965 T2432 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 13
   [junit4]   2> 561965 T2432 oass.SolrIndexSearcher.<init> Opening Searcher@5de1f955 main
   [junit4]   2> 561966 T2432 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561966 T2433 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561968 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5de1f955 main{StandardDirectoryReader(segments_d:35:nrt _7(4.7):c1 _9(4.7):c1)}
   [junit4]   2> 561971 T2433 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_d,generation=13}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_e,generation=14}
   [junit4]   2> 561972 T2433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 14
   [junit4]   2> 561972 T2433 oass.SolrIndexSearcher.<init> Opening Searcher@1af06642 main
   [junit4]   2> 561973 T2433 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561973 T2431 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561975 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1af06642 main{StandardDirectoryReader(segments_e:39:nrt _a(4.7):c1)}
   [junit4]   2> 561977 T2431 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_e,generation=14}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_f,generation=15}
   [junit4]   2> 561977 T2431 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 15
   [junit4]   2> 561978 T2431 oass.SolrIndexSearcher.<init> Opening Searcher@adcbb654 main
   [junit4]   2> 561979 T2431 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561979 T2432 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561980 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@adcbb654 main{StandardDirectoryReader(segments_f:41:nrt _a(4.7):c1 _b(4.7):c1)}
   [junit4]   2> 561985 T2432 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_f,generation=15}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_g,generation=16}
   [junit4]   2> 561986 T2432 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 16
   [junit4]   2> 561996 T2432 oass.SolrIndexSearcher.<init> Opening Searcher@e983f615 main
   [junit4]   2> 561997 T2432 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 561997 T2433 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 561998 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e983f615 main{StandardDirectoryReader(segments_g:49:nrt _a(4.7):c1 _d(4.7):c1)}
   [junit4]   2> 561998 T2433 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_g,generation=16}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_h,generation=17}
   [junit4]   2> 561999 T2433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 17
   [junit4]   2> 561999 T2433 oass.SolrIndexSearcher.<init> Opening Searcher@c346bf9a main
   [junit4]   2> 562000 T2433 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562000 T2431 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562001 T2431 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 562001 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c346bf9a main{StandardDirectoryReader(segments_g:49:nrt _a(4.7):c1 _d(4.7):c1)}
   [junit4]   2> 562004 T2431 oass.SolrIndexSearcher.<init> Opening Searcher@8cd46beb main
   [junit4]   2> 562005 T2431 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562005 T2432 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562006 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8cd46beb main{StandardDirectoryReader(segments_h:51:nrt _a(4.7):c1 _d(4.7):c1 _e(4.7):c1)}
   [junit4]   2> 562017 T2432 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_h,generation=17}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_i,generation=18}
   [junit4]   2> 562017 T2432 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 18
   [junit4]   2> 562018 T2432 oass.SolrIndexSearcher.<init> Opening Searcher@3ff25969 main
   [junit4]   2> 562019 T2432 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562019 T2433 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562020 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3ff25969 main{StandardDirectoryReader(segments_i:55:nrt _a(4.7):c1 _d(4.7):c1 _f(4.7):c1)}
   [junit4]   2> 562027 T2433 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_i,generation=18}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_j,generation=19}
   [junit4]   2> 562028 T2433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 19
   [junit4]   2> 562035 T2433 oass.SolrIndexSearcher.<init> Opening Searcher@f1242236 main
   [junit4]   2> 562036 T2433 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562037 T2431 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562038 T2431 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_j,generation=19}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_k,generation=20}
   [junit4]   2> 562038 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f1242236 main{StandardDirectoryReader(segments_j:63:nrt _d(4.7):c1 _g(4.7):c1 _h(4.7):c1)}
   [junit4]   2> 562038 T2431 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 20
   [junit4]   2> 562039 T2431 oass.SolrIndexSearcher.<init> Opening Searcher@444df9fd main
   [junit4]   2> 562040 T2431 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562041 T2432 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562041 T2432 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 562043 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@444df9fd main{StandardDirectoryReader(segments_j:63:nrt _d(4.7):c1 _g(4.7):c1 _h(4.7):c1)}
   [junit4]   2> 562043 T2432 oass.SolrIndexSearcher.<init> Opening Searcher@da0872bb main
   [junit4]   2> 562044 T2432 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562045 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@da0872bb main{StandardDirectoryReader(segments_j:63:nrt _d(4.7):c1 _g(4.7):c1 _h(4.7):c1)}
   [junit4]   2> 562047 T2433 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562060 T2433 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_k,generation=20}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_l,generation=21}
   [junit4]   2> 562060 T2433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 21
   [junit4]   2> 562068 T2433 oass.SolrIndexSearcher.<init> Opening Searcher@9e37d083 main
   [junit4]   2> 562070 T2433 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562070 T2431 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562071 T2431 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_l,generation=21}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_m,generation=22}
   [junit4]   2> 562072 T2431 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 22
   [junit4]   2> 562071 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9e37d083 main{StandardDirectoryReader(segments_l:71:nrt _d(4.7):c1 _i(4.7):c2/1:delGen=1 _j(4.7):c1)}
   [junit4]   2> 562072 T2431 oass.SolrIndexSearcher.<init> Opening Searcher@211e0f22 main
   [junit4]   2> 562073 T2431 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562073 T2432 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562074 T2432 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 562074 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@211e0f22 main{StandardDirectoryReader(segments_l:71:nrt _d(4.7):c1 _i(4.7):c2/1:delGen=1 _j(4.7):c1)}
   [junit4]   2> 562081 T2432 oass.SolrIndexSearcher.<init> Opening Searcher@4e7c02d4 main
   [junit4]   2> 562082 T2432 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562082 T2433 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562083 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4e7c02d4 main{StandardDirectoryReader(segments_m:76:nrt _d(4.7):c1 _i(4.7):c2/1:delGen=1 _k(4.7):c1)}
   [junit4]   2> 562090 T2433 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_m,generation=22}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_n,generation=23}
   [junit4]   2> 562091 T2433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 23
   [junit4]   2> 562098 T2433 oass.SolrIndexSearcher.<init> Opening Searcher@2b0fd86c main
   [junit4]   2> 562099 T2433 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562100 T2431 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562100 T2431 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_n,generation=23}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_o,generation=24}
   [junit4]   2> 562101 T2431 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 24
   [junit4]   2> 562101 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2b0fd86c main{StandardDirectoryReader(segments_n:81:nrt _d(4.7):c1 _i(4.7):c2/1:delGen=1 _l(4.7):c1 _m(4.7):c1)}
   [junit4]   2> 562103 T2431 oass.SolrIndexSearcher.<init> Opening Searcher@20b232f4 main
   [junit4]   2> 562103 T2431 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562104 T2432 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562104 T2432 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 562105 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@20b232f4 main{StandardDirectoryReader(segments_n:81:nrt _d(4.7):c1 _i(4.7):c2/1:delGen=1 _l(4.7):c1 _m(4.7):c1)}
   [junit4]   2> 562113 T2432 oass.SolrIndexSearcher.<init> Opening Searcher@82be3458 main
   [junit4]   2> 562113 T2432 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562114 T2433 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562115 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@82be3458 main{StandardDirectoryReader(segments_o:86:nrt _i(4.7):c2/1:delGen=1 _l(4.7):c1 _n(4.7):c1)}
   [junit4]   2> 562121 T2433 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_o,generation=24}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_p,generation=25}
   [junit4]   2> 562122 T2433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 25
   [junit4]   2> 562124 T2433 oass.SolrIndexSearcher.<init> Opening Searcher@4f82411e main
   [junit4]   2> 562125 T2433 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562126 T2431 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562127 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4f82411e main{StandardDirectoryReader(segments_p:93:nrt _l(4.7):c1 _p(4.7):c1)}
   [junit4]   2> 562129 T2431 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_p,generation=25}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_q,generation=26}
   [junit4]   2> 562129 T2431 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 26
   [junit4]   2> 562130 T2431 oass.SolrIndexSearcher.<init> Opening Searcher@ec386f38 main
   [junit4]   2> 562130 T2431 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562131 T2432 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562133 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ec386f38 main{StandardDirectoryReader(segments_p:93:nrt _l(4.7):c1 _p(4.7):c1)}
   [junit4]   2> 562135 T2432 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_q,generation=26}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_r,generation=27}
   [junit4]   2> 562135 T2432 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 27
   [junit4]   2> 562140 T2432 oass.SolrIndexSearcher.<init> Opening Searcher@153d810e main
   [junit4]   2> 562140 T2432 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562141 T2433 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562141 T2433 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_r,generation=27}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_s,generation=28}
   [junit4]   2> 562142 T2433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 28
   [junit4]   2> 562142 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@153d810e main{StandardDirectoryReader(segments_r:101:nrt _l(4.7):c1 _r(4.7):c1)}
   [junit4]   2> 562143 T2433 oass.SolrIndexSearcher.<init> Opening Searcher@795e972e main
   [junit4]   2> 562143 T2433 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562144 T2431 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562144 T2431 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 562145 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@795e972e main{StandardDirectoryReader(segments_r:101:nrt _l(4.7):c1 _r(4.7):c1)}
   [junit4]   2> 562150 T2431 oass.SolrIndexSearcher.<init> Opening Searcher@b5fa7bf1 main
   [junit4]   2> 562151 T2431 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562152 T2432 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562153 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b5fa7bf1 main{StandardDirectoryReader(segments_s:104:nrt _l(4.7):c1 _r(4.7):c1 _s(4.7):c1)}
   [junit4]   2> 562157 T2432 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_s,generation=28}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_t,generation=29}
   [junit4]   2> 562157 T2432 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 29
   [junit4]   2> 562158 T2432 oass.SolrIndexSearcher.<init> Opening Searcher@15ce73d7 main
   [junit4]   2> 562158 T2432 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562158 T2433 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562160 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15ce73d7 main{StandardDirectoryReader(segments_t:107:nrt _r(4.7):c1 _t(4.7):c1)}
   [junit4]   2> 562160 T2433 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_t,generation=29}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_u,generation=30}
   [junit4]   2> 562161 T2433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 30
   [junit4]   2> 562164 T2433 oass.SolrIndexSearcher.<init> Opening Searcher@13538a9c main
   [junit4]   2> 562164 T2433 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562165 T2431 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562165 T2431 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_u,generation=30}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_v,generation=31}
   [junit4]   2> 562166 T2431 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 31
   [junit4]   2> 562166 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@13538a9c main{StandardDirectoryReader(segments_u:111:nrt _r(4.7):c1 _u(4.7):c1)}
   [junit4]   2> 562167 T2431 oass.SolrIndexSearcher.<init> Opening Searcher@bcb63aa6 main
   [junit4]   2> 562167 T2431 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562168 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@bcb63aa6 main{StandardDirectoryReader(segments_u:111:nrt _r(4.7):c1 _u(4.7):c1)}
   [junit4]   2> ASYNC  NEW_CORE C1128 name=collection1 org.apache.solr.core.SolrCore@d78ee463
   [junit4]   2> 562169 T2420 C1128 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562170 T2420 C1128 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 562170 T2420 C1128 oass.SolrIndexSearcher.<init> Opening Searcher@636be138 main
   [junit4]   2> 562171 T2420 C1128 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562172 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@636be138 main{StandardDirectoryReader(segments_u:111:nrt _r(4.7):c1 _u(4.7):c1)}
   [junit4]   2> 562172 T2420 C1128 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 562174 T2420 oas.SolrTestCaseJ4.tearDown ###Ending testMultiThreaded
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SignatureUpdateProcessorFactoryTest -Dtests.method=testMultiThreaded -Dtests.seed=D0E2D4BE718E1C9B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_PY -Dtests.timezone=America/Louisville -Dtests.file.encoding=US-ASCII
   [junit4] FAILURE 0.58s J0 | SignatureUpdateProcessorFactoryTest.testMultiThreaded <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: expected:<1> but was:<2>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([D0E2D4BE718E1C9B:B1770E5E995F166D]:0)
   [junit4]    > 	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.checkNumDocs(SignatureUpdateProcessorFactoryTest.java:71)
   [junit4]    > 	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testMultiThreaded(SignatureUpdateProcessorFactoryTest.java:222)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:780)
   [junit4]   2> 562181 T2420 oas.SolrTestCaseJ4.setUp ###Starting testDupeDetection
   [junit4]   2> 562182 T2420 C1128 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 562182 T2420 C1128 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 562183 T2420 C1128 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562184 T2420 C1128 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_v,generation=31}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_w,generation=32}
   [junit4]   2> 562185 T2420 C1128 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 32
   [junit4]   2> 562185 T2420 C1128 oass.SolrIndexSearcher.<init> Opening Searcher@ebcc6312 main
   [junit4]   2> 562186 T2420 C1128 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562187 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ebcc6312 main{StandardDirectoryReader(segments_w:112:nrt)}
   [junit4]   2> 562188 T2420 C1128 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 562192 T2420 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562196 T2420 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_w,generation=32}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_x,generation=33}
   [junit4]   2> 562197 T2420 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 33
   [junit4]   2> 562198 T2420 oass.SolrIndexSearcher.<init> Opening Searcher@b11bbe48 main
   [junit4]   2> 562198 T2420 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562199 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b11bbe48 main{StandardDirectoryReader(segments_x:114:nrt _v(4.7):c2)}
   [junit4]   2> 562202 T2420 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562207 T2420 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_x,generation=33}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_y,generation=34}
   [junit4]   2> 562207 T2420 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 34
   [junit4]   2> 562208 T2420 oass.SolrIndexSearcher.<init> Opening Searcher@287f09fc main
   [junit4]   2> 562208 T2420 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562210 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@287f09fc main{StandardDirectoryReader(segments_y:116:nrt _v(4.7):c2 _w(4.7):c1)}
   [junit4]   2> 562210 T2420 oas.SolrTestCaseJ4.tearDown ###Ending testDupeDetection
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SignatureUpdateProcessorFactoryTest -Dtests.method=testDupeDetection -Dtests.seed=D0E2D4BE718E1C9B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_PY -Dtests.timezone=America/Louisville -Dtests.file.encoding=US-ASCII
   [junit4] FAILURE 0.04s J0 | SignatureUpdateProcessorFactoryTest.testDupeDetection <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: expected:<1> but was:<3>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([D0E2D4BE718E1C9B:8BD22F7672C9BFE7]:0)
   [junit4]    > 	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.checkNumDocs(SignatureUpdateProcessorFactoryTest.java:71)
   [junit4]    > 	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testDupeDetection(SignatureUpdateProcessorFactoryTest.java:119)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:780)
   [junit4]   2> 562219 T2420 oas.SolrTestCaseJ4.setUp ###Starting testDupeAllFieldsDetection
   [junit4]   2> 562219 T2420 C1128 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 562220 T2420 C1128 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 562223 T2420 C1128 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562224 T2420 C1128 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_y,generation=34}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_z,generation=35}
   [junit4]   2> 562224 T2420 C1128 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 35
   [junit4]   2> 562225 T2420 C1128 oass.SolrIndexSearcher.<init> Opening Searcher@88b85471 main
   [junit4]   2> 562227 T2420 C1128 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562229 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@88b85471 main{StandardDirectoryReader(segments_z:117:nrt)}
   [junit4]   2> 562229 T2420 C1128 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 7
   [junit4]   2> 562242 T2420 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 562245 T2420 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_z,generation=35}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@aa912cfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6909172c)),segFN=segments_10,generation=36}
   [junit4]   2> 562246 T2420 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 36
   [junit4]   2> 562249 T2420 oass.SolrIndexSearcher.<init> Opening Searcher@a10672ff main
   [junit4]   2> 562250 T2420 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 562252 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a10672ff main{StandardDirectoryReader(segments_10:119:nrt _x(4.7):c3)}
   [junit4]   2> 562253 T2420 oas.SolrTestCaseJ4.tearDown ###Ending testDupeAllFieldsDetection
   [junit4]   2> 562257 T2420 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 562258 T2420 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1381416246
   [junit4]   2> 562259 T2420 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@d78ee463
   [junit4]   2> 562274 T2420 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=42,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=253,cumulative_deletesById=0,cumulative_deletesByQuery=6,cumulative_errors=0}
   [junit4]   2> 562274 T2420 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 562275 T2420 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 562275 T2420 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 562276 T2420 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 562277 T2420 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 562277 T2420 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808/index;done=false>>]
   [junit4]   2> 562278 T2420 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808/index
   [junit4]   2> 562278 T2420 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808;done=false>>]
   [junit4]   2> 562279 T2420 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1390642733808
   [junit4]   2> NOTE: test params are: codec=Lucene3x, sim=DefaultSimilarity, locale=es_PY, timezone=America/Louisville
   [junit4]   2> NOTE: Linux 3.8.0-35-generic amd64/IBM Corporation 1.7.0 (64-bit)/cpus=8,threads=1,free=138425792,total=290848768
   [junit4]   2> NOTE: All tests run in this JVM: [TestCustomSort, SampleTest, UpdateRequestProcessorFactoryTest, TestSolrQueryParser, TestGroupingSearch, CachingDirectoryFactoryTest, PrimitiveFieldTypeTest, TestSchemaNameResource, SchemaVersionSpecificBehaviorTest, BadCopyFieldTest, AutoCommitTest, SolrInfoMBeanTest, ZkControllerTest, DocValuesMissingTest, LegacyHTMLStripCharFilterTest, TestSolrXmlPersistor, TestClassNameShortening, AnalysisAfterCoreReloadTest, TestDistribDocBasedVersion, OverseerCollectionProcessorTest, StressHdfsTest, BasicDistributedZkTest, TestReversedWildcardFilterFactory, SolrCoreTest, FieldMutatingUpdateProcessorTest, ConnectionManagerTest, SOLR749Test, TestInfoStreamLogging, QueryEqualityTest, MoreLikeThisHandlerTest, TestSort, LeaderElectionTest, TestSolrQueryParserDefaultOperatorResource, TestImplicitCoreProperties, TestSystemIdResolver, TestFunctionQuery, LukeRequestHandlerTest, TestStressVersions, TestReplicationHandler, TestLFUCache, TestPerFieldSimilarity, TestRemoteStreaming, TestFreeTextSuggestions, TestFieldResource, BasicFunctionalityTest, ChangedSchemaMergeTest, DistribCursorPagingTest, HdfsBasicDistributedZk2Test, DistributedTermsComponentTest, PolyFieldTest, UpdateParamsTest, EchoParamsTest, TestCloudManagedSchemaAddField, PeerSyncTest, TestSearchPerf, BadComponentTest, CacheHeaderTest, TestDefaultSearchFieldResource, SolrIndexSplitterTest, TestCloudManagedSchema, SuggesterFSTTest, TestFaceting, DocumentBuilderTest, WordBreakSolrSpellCheckerTest, LoggingHandlerTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestDynamicFieldResource, CopyFieldTest, TestCoreContainer, BlockDirectoryTest, RegexBoostProcessorTest, DeleteReplicaTest, TestStressUserVersions, DOMUtilTest, SuggesterTest, MBeansHandlerTest, DateMathParserTest, TestBadConfig, SpellPossibilityIteratorTest, BinaryUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, TestJoin, QueryParsingTest, BasicDistributedZk2Test, UnloadDistributedZkTest, SyncSliceTest, OpenCloseCoreStressTest, OverseerTest, ShardRoutingTest, BasicZkTest, TestRandomDVFaceting, TestRangeQuery, StatsComponentTest, SpellCheckComponentTest, BadIndexSchemaTest, TestFiltering, SimplePostToolTest, TestCoreDiscovery, SignatureUpdateProcessorFactoryTest]
   [junit4] Completed on J0 in 1.91s, 6 tests, 2 failures <<< FAILURES!

[...truncated 436 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:452: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1308: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:941: There were test failures: 355 suites, 1547 tests, 2 failures, 68 ignored (7 assumptions)

Total time: 36 minutes 31 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure