You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/08/08 17:45:52 UTC
[JENKINS] Lucene-Solr-NightlyTests-4.x - Build # 593 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/593/
1 tests failed.
REGRESSION: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testDistribSearch
Error Message:
IOException occured when talking to server at: http://127.0.0.1:30047/_sd/ya/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:30047/_sd/ya/collection1
at __randomizedtesting.SeedInfo.seed([2F90961CE3B07E66:AE76180494EF1E5A]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:563)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.cloud.CloudInspectUtil.compareResults(CloudInspectUtil.java:223)
at org.apache.solr.cloud.CloudInspectUtil.compareResults(CloudInspectUtil.java:165)
at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testIndexingBatchPerRequestWithHttpSolrServer(FullSolrCloudDistribCmdsTest.java:414)
at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.doTest(FullSolrCloudDistribCmdsTest.java:144)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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:65)
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:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:365)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
at org.apache.http.impl.io.AbstractSessionOutputBuffer.flushBuffer(AbstractSessionOutputBuffer.java:159)
at org.apache.http.impl.io.AbstractSessionOutputBuffer.writeLine(AbstractSessionOutputBuffer.java:258)
at org.apache.http.impl.io.HttpRequestWriter.writeHeadLine(HttpRequestWriter.java:59)
at org.apache.http.impl.io.HttpRequestWriter.writeHeadLine(HttpRequestWriter.java:46)
at org.apache.http.impl.io.AbstractMessageWriter.write(AbstractMessageWriter.java:109)
at org.apache.http.impl.AbstractHttpClientConnection.sendRequestHeader(AbstractHttpClientConnection.java:254)
at org.apache.http.impl.conn.DefaultClientConnection.sendRequestHeader(DefaultClientConnection.java:270)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.sendRequestHeader(ManagedClientConnectionImpl.java:209)
at org.apache.http.protocol.HttpRequestExecutor.doSendRequest(HttpRequestExecutor.java:203)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:121)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:682)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:486)
at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:449)
... 50 more
Build Log:
[...truncated 14190 lines...]
[junit4] Suite: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/init-core-data-001
[junit4] 2> 3858921 T11953 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_sd/ya
[junit4] 2> 3858924 T11953 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 3858925 T11953 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 3858926 T11954 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 3859026 T11953 oasc.ZkTestServer.run start zk server on port:53895
[junit4] 2> 3859027 T11953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3859031 T11960 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11afc564 name:ZooKeeperConnection Watcher:127.0.0.1:53895 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3859031 T11953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3859031 T11953 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 3859035 T11953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3859036 T11962 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6bdf7d45 name:ZooKeeperConnection Watcher:127.0.0.1:53895/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3859036 T11953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3859036 T11953 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 3859038 T11953 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 3859039 T11953 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 3859040 T11953 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 3859042 T11953 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 3859042 T11953 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 3859044 T11953 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 3859045 T11953 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 3859147 T11953 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 3859148 T11953 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 3859150 T11953 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 3859150 T11953 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 3859152 T11953 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 3859153 T11953 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 3859154 T11953 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 3859155 T11953 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 3859157 T11953 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 3859157 T11953 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 3859159 T11953 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 3859160 T11953 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 3859162 T11953 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 3859162 T11953 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 3859164 T11953 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 3859165 T11953 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 3859166 T11953 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 3859167 T11953 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 3860300 T11953 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 3860305 T11953 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:30047
[junit4] 2> 3860305 T11953 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 3860306 T11953 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 3860306 T11953 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-002
[junit4] 2> 3860306 T11953 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-002/'
[junit4] 2> 3860336 T11953 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-002/solr.xml
[junit4] 2> 3860387 T11953 oasc.CoreContainer.<init> New CoreContainer 990570062
[junit4] 2> 3860387 T11953 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-002/]
[junit4] 2> 3860388 T11953 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 3860388 T11953 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 3860388 T11953 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 3860389 T11953 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 3860389 T11953 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 3860389 T11953 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 3860389 T11953 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 3860390 T11953 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 3860390 T11953 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 3860390 T11953 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 3860391 T11953 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 3860391 T11953 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 3860391 T11953 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 3860391 T11953 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53895/solr
[junit4] 2> 3860392 T11953 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 3860392 T11953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3860394 T11973 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4896292a name:ZooKeeperConnection Watcher:127.0.0.1:53895 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3860394 T11953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3860397 T11953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3860398 T11975 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f926a08 name:ZooKeeperConnection Watcher:127.0.0.1:53895/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3860398 T11953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3860400 T11953 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 3860402 T11953 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 3860403 T11953 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 3860405 T11953 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 3860407 T11953 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 3860409 T11953 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 3860410 T11953 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:30047__sd%2Fya
[junit4] 2> 3860411 T11953 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:30047__sd%2Fya
[junit4] 2> 3860412 T11953 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 3860414 T11953 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 3860416 T11953 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:30047__sd%2Fya
[junit4] 2> 3860416 T11953 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 3860417 T11953 oasc.Overseer.start Overseer (id=92242611182895107-127.0.0.1:30047__sd%2Fya-n_0000000000) starting
[junit4] 2> 3860419 T11953 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 3860424 T11977 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 3860424 T11953 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 3860426 T11953 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 3860427 T11953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 3860429 T11976 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 3860434 T11978 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 3860434 T11978 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3860435 T11978 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 3860435 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3860436 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3860436 T11976 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:30047/_sd/ya",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:30047__sd%2Fya",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 3860437 T11976 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 3860437 T11976 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 3860439 T11979 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> 3861435 T11978 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 3861436 T11978 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 3861436 T11978 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 3861437 T11978 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 3861437 T11978 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3861438 T11978 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-002/collection1/'
[junit4] 2> 3861440 T11978 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 3861440 T11978 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 3861441 T11978 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 3861503 T11978 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
[junit4] 2> 3861546 T11978 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 3861647 T11978 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 3861656 T11978 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 3862023 T11978 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 3862026 T11978 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3862028 T11978 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3862032 T11978 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3862048 T11978 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 3862048 T11978 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 3862049 T11978 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-002/collection1/, dataDir=./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/control/data/
[junit4] 2> 3862049 T11978 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@290f6b0c
[junit4] 2> 3862051 T11978 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/control/data
[junit4] 2> 3862051 T11978 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/control/data/index/
[junit4] 2> 3862052 T11978 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 3862053 T11978 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/control/data/index
[junit4] 2> 3862053 T11978 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=6, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 3862056 T11978 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/index-SimpleFSDirectory-001 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@fb9c1a),segFN=segments_1,generation=1}
[junit4] 2> 3862056 T11978 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3862059 T11978 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 3862059 T11978 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 3862060 T11978 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 3862060 T11978 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 3862060 T11978 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 3862060 T11978 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 3862061 T11978 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3862061 T11978 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3862061 T11978 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 3862062 T11978 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3862062 T11978 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3862063 T11978 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3862063 T11978 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3862064 T11978 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 3862064 T11978 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 3862064 T11978 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 3862064 T11978 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 3862065 T11978 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3862065 T11978 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3862065 T11978 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 3862066 T11978 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 3862085 T11978 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3862087 T11978 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3862088 T11978 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3862090 T11978 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3862092 T11978 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3862098 T11978 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3862098 T11978 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3862099 T11978 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1470702014, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 3862101 T11978 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/index-SimpleFSDirectory-001 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@fb9c1a),segFN=segments_1,generation=1}
[junit4] 2> 3862101 T11978 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3862101 T11978 oass.SolrIndexSearcher.<init> Opening Searcher@7e4478[collection1] main
[junit4] 2> 3862102 T11978 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 3862102 T11978 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3862103 T11978 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 3862103 T11978 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 3862103 T11978 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 3862104 T11978 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3862104 T11978 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 3862104 T11978 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3862105 T11978 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json
[junit4] 2> 3862106 T11978 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json
[junit4] 2> 3862107 T11978 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3862107 T11978 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 3862109 T11980 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7e4478[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 3862111 T11978 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 3862111 T11983 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:30047/_sd/ya collection:control_collection shard:shard1
[junit4] 2> 3862112 T11953 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 3862112 T11953 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 3862112 T11983 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 3862113 T11953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3862115 T11985 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c5a71b3 name:ZooKeeperConnection Watcher:127.0.0.1:53895/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3862115 T11953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3862118 T11953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 3862119 T11983 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 3862119 T11953 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 3862120 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3862120 T11983 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 3862121 T11983 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C11446 name=collection1 org.apache.solr.core.SolrCore@648819c8 url=http://127.0.0.1:30047/_sd/ya/collection1 node=127.0.0.1:30047__sd%2Fya C11446_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:30047/_sd/ya, core=collection1, node_name=127.0.0.1:30047__sd%2Fya}
[junit4] 2> 3862121 T11983 C11446 P30047 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:30047/_sd/ya/collection1/
[junit4] 2> 3862121 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3862121 T11983 C11446 P30047 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 3862122 T11983 C11446 P30047 oasc.SyncStrategy.syncToMe http://127.0.0.1:30047/_sd/ya/collection1/ has no replicas
[junit4] 2> 3862122 T11983 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:30047/_sd/ya/collection1/ shard1
[junit4] 2> 3862122 T11983 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 3862123 T11979 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> 3862124 T11986 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> 3862126 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3862127 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3862230 T11979 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> 3862230 T11986 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> 3862279 T11983 oasc.ZkController.register We are http://127.0.0.1:30047/_sd/ya/collection1/ and leader is http://127.0.0.1:30047/_sd/ya/collection1/
[junit4] 2> 3862280 T11983 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:30047/_sd/ya
[junit4] 2> 3862280 T11983 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 3862280 T11983 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 3862280 T11983 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3862281 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3862282 T11983 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3862282 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3862283 T11976 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:30047/_sd/ya",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:30047__sd%2Fya",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 3862386 T11979 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> 3862386 T11986 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> 3863266 T11953 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 3863267 T11953 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 3863270 T11953 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:59459
[junit4] 2> 3863270 T11953 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 3863271 T11953 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 3863271 T11953 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-003
[junit4] 2> 3863271 T11953 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-003/'
[junit4] 2> 3863301 T11953 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-003/solr.xml
[junit4] 2> 3863351 T11953 oasc.CoreContainer.<init> New CoreContainer 2092249032
[junit4] 2> 3863352 T11953 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-003/]
[junit4] 2> 3863353 T11953 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 3863353 T11953 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 3863353 T11953 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 3863353 T11953 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 3863354 T11953 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 3863354 T11953 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 3863354 T11953 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 3863354 T11953 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 3863355 T11953 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 3863355 T11953 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 3863355 T11953 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 3863356 T11953 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 3863356 T11953 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 3863356 T11953 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53895/solr
[junit4] 2> 3863356 T11953 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 3863357 T11953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3863358 T11997 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b54336e name:ZooKeeperConnection Watcher:127.0.0.1:53895 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3863359 T11953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3863362 T11953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3863362 T11999 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15e4cea6 name:ZooKeeperConnection Watcher:127.0.0.1:53895/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3863363 T11953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3863367 T11953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 3864370 T11953 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59459__sd%2Fya
[junit4] 2> 3864371 T11953 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59459__sd%2Fya
[junit4] 2> 3864374 T11979 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 3864375 T12000 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 3864374 T11986 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 3864382 T12001 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 3864382 T12001 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3864383 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3864383 T12001 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 3864384 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3864385 T11976 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:59459/_sd/ya",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59459__sd%2Fya",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 3864385 T11976 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 3864385 T11976 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 3864387 T11986 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> 3864387 T12000 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> 3864387 T11979 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> 3865384 T12001 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 3865385 T12001 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 3865385 T12001 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 3865386 T12001 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 3865386 T12001 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3865387 T12001 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-003/collection1/'
[junit4] 2> 3865389 T12001 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 3865389 T12001 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 3865390 T12001 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 3865466 T12001 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
[junit4] 2> 3865509 T12001 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 3865611 T12001 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 3865620 T12001 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 3865984 T12001 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 3865987 T12001 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3865989 T12001 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3865993 T12001 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3866010 T12001 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 3866010 T12001 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 3866011 T12001 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-003/collection1/, dataDir=./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/jetty1/
[junit4] 2> 3866011 T12001 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@290f6b0c
[junit4] 2> 3866013 T12001 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/jetty1
[junit4] 2> 3866014 T12001 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/jetty1/index/
[junit4] 2> 3866014 T12001 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 3866017 T12001 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/jetty1/index
[junit4] 2> 3866017 T12001 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=6, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 3866020 T12001 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/index-SimpleFSDirectory-002 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3081f390),segFN=segments_1,generation=1}
[junit4] 2> 3866020 T12001 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3866023 T12001 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 3866024 T12001 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 3866024 T12001 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 3866024 T12001 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 3866025 T12001 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 3866025 T12001 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 3866025 T12001 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3866026 T12001 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3866026 T12001 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 3866027 T12001 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3866027 T12001 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3866027 T12001 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3866028 T12001 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3866028 T12001 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 3866029 T12001 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 3866029 T12001 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 3866029 T12001 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 3866030 T12001 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3866030 T12001 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3866030 T12001 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 3866031 T12001 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 3866050 T12001 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3866052 T12001 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3866054 T12001 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3866056 T12001 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3866057 T12001 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3866062 T12001 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3866062 T12001 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3866064 T12001 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1470702014, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 3866066 T12001 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/index-SimpleFSDirectory-002 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3081f390),segFN=segments_1,generation=1}
[junit4] 2> 3866066 T12001 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3866066 T12001 oass.SolrIndexSearcher.<init> Opening Searcher@39d3be2b[collection1] main
[junit4] 2> 3866067 T12001 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 3866068 T12001 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3866068 T12001 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 3866068 T12001 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 3866068 T12001 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 3866069 T12001 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3866069 T12001 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 3866070 T12001 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3866070 T12001 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 3866070 T12001 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 3866073 T12002 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@39d3be2b[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 3866076 T12001 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 3866077 T12005 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59459/_sd/ya collection:collection1 shard:shard3
[junit4] 2> 3866077 T11953 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 3866077 T11953 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 3866077 T12005 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 3866082 T12005 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
[junit4] 2> 3866083 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3866083 T12005 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 3866084 T12005 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C11447 name=collection1 org.apache.solr.core.SolrCore@828538d url=http://127.0.0.1:59459/_sd/ya/collection1 node=127.0.0.1:59459__sd%2Fya C11447_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:59459/_sd/ya, core=collection1, node_name=127.0.0.1:59459__sd%2Fya}
[junit4] 2> 3866084 T12005 C11447 P59459 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59459/_sd/ya/collection1/
[junit4] 2> 3866084 T12005 C11447 P59459 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 3866084 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3866084 T12005 C11447 P59459 oasc.SyncStrategy.syncToMe http://127.0.0.1:59459/_sd/ya/collection1/ has no replicas
[junit4] 2> 3866085 T12005 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59459/_sd/ya/collection1/ shard3
[junit4] 2> 3866085 T12005 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 3866087 T12000 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> 3866087 T11986 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> 3866087 T11979 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> 3866089 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3866090 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3866193 T11979 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> 3866193 T12000 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> 3866193 T11986 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> 3866242 T12005 oasc.ZkController.register We are http://127.0.0.1:59459/_sd/ya/collection1/ and leader is http://127.0.0.1:59459/_sd/ya/collection1/
[junit4] 2> 3866242 T12005 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59459/_sd/ya
[junit4] 2> 3866242 T12005 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 3866242 T12005 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 3866242 T12005 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3866243 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3866244 T12005 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3866244 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3866245 T11976 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:59459/_sd/ya",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59459__sd%2Fya",
[junit4] 2> "shard":"shard3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 3866348 T11979 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> 3866348 T11986 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> 3866348 T12000 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> 3867236 T11953 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 3867237 T11953 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 3867240 T11953 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:26648
[junit4] 2> 3867241 T11953 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 3867241 T11953 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 3867241 T11953 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-004
[junit4] 2> 3867241 T11953 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-004/'
[junit4] 2> 3867271 T11953 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-004/solr.xml
[junit4] 2> 3867321 T11953 oasc.CoreContainer.<init> New CoreContainer 2035010764
[junit4] 2> 3867322 T11953 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-004/]
[junit4] 2> 3867323 T11953 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 3867323 T11953 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 3867323 T11953 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 3867323 T11953 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 3867324 T11953 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 3867324 T11953 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 3867324 T11953 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 3867324 T11953 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 3867324 T11953 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 3867325 T11953 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 3867325 T11953 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 3867325 T11953 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 3867326 T11953 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 3867326 T11953 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53895/solr
[junit4] 2> 3867326 T11953 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 3867327 T11953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3867328 T12016 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f72a34a name:ZooKeeperConnection Watcher:127.0.0.1:53895 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3867329 T11953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3867331 T11953 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3867332 T12018 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10a1c58f name:ZooKeeperConnection Watcher:127.0.0.1:53895/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3867332 T11953 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3867337 T11953 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 3868339 T11953 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:26648__sd%2Fya
[junit4] 2> 3868340 T11953 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:26648__sd%2Fya
[junit4] 2> 3868343 T11979 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 3868343 T12019 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 3868343 T12000 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 3868343 T11986 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 3868350 T12020 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 3868350 T12020 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3868351 T12020 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 3868351 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3868352 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3868353 T11976 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:26648/_sd/ya",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:26648__sd%2Fya",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 3868353 T11976 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 3868353 T11976 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 3868355 T12000 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> 3868355 T11986 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> 3868355 T12019 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> 3868355 T11979 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> 3869351 T12020 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 3869352 T12020 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 3869353 T12020 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 3869353 T12020 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 3869353 T12020 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3869354 T12020 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-004/collection1/'
[junit4] 2> 3869356 T12020 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 3869357 T12020 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 3869357 T12020 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 3869420 T12020 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
[junit4] 2> 3869465 T12020 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 3869566 T12020 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 3869575 T12020 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 3869942 T12020 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 3869945 T12020 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3869947 T12020 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3869951 T12020 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3869967 T12020 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 3869968 T12020 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 3869968 T12020 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-004/collection1/, dataDir=./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/jetty2/
[junit4] 2> 3869968 T12020 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@290f6b0c
[junit4] 2> 3869972 T12020 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/jetty2
[junit4] 2> 3869973 T12020 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/jetty2/index/
[junit4] 2> 3869973 T12020 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 3869975 T12020 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/tempDir-001/jetty2/index
[junit4] 2> 3869975 T12020 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=6, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 3869978 T12020 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/index-SimpleFSDirectory-003 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@462a284f),segFN=segments_1,generation=1}
[junit4] 2> 3869978 T12020 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3869982 T12020 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 3869982 T12020 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 3869982 T12020 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 3869983 T12020 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 3869983 T12020 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 3869983 T12020 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 3869983 T12020 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3869984 T12020 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3869984 T12020 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 3869985 T12020 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3869985 T12020 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3869985 T12020 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3869986 T12020 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3869986 T12020 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 3869987 T12020 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 3869987 T12020 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 3869987 T12020 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 3869988 T12020 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 3869988 T12020 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3869988 T12020 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 3869989 T12020 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 3870008 T12020 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3870010 T12020 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3870011 T12020 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3870013 T12020 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3870015 T12020 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3870020 T12020 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3870020 T12020 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3870021 T12020 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1470702014, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 3870023 T12020 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2F90961CE3B07E66-001/index-SimpleFSDirectory-003 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@462a284f),segFN=segments_1,generation=1}
[junit4] 2> 3870023 T12020 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3870023 T12020 oass.SolrIndexSearcher.<init> Opening Searcher@2c589765[collection1] main
[junit4] 2> 3870024 T12020 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 3870024 T12020 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3870025 T12020 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 3870025 T12020 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 3870025 T12020 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 3870026 T12020 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3870026 T12020 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 3870027 T12020 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3870027 T12020 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 3870027 T12020 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 3870030 T12021 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2c589765[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 3870032 T12020 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 3870033 T12024 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:26648/_sd/ya collection:collection1 shard:shard2
[junit4] 2> 3870033 T11953 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4] 2> 3870034 T11953 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 3870034 T12024 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 3870038 T12024 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 3870039 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3870039 T12024 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 3870040 T12024 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C11448 name=collection1 org.apache.solr.core.SolrCore@79773203 url=http://127.0.0.1:26648/_sd/ya/collection1 node=127.0.0.1:26648__sd%2Fya C11448_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:26648/_sd/ya, core=collection1, node_name=127.0.0.1:26648__sd%2Fya}
[junit4] 2> 3870040 T12024 C11448 P26648 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:26648/_sd/ya/collection1/
[junit4] 2> 3870040 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3870040 T12024 C11448 P26648 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 3870041 T12024 C11448 P26648 oasc.SyncStrategy.syncToMe http://127.0.0.1:26648/_sd/ya/collection1/ has no replicas
[junit4] 2> 3870041 T12024 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:26648/_sd/ya/collection1/ shard2
[junit4] 2> 3870041 T12024 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 3870042 T11979 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> 3870042 T11986 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> 3870042 T12019 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> 3870042 T12000 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> 3870045 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3870047 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3870047 T12019 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> 3870048 T11979 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> 3870048 T12000 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> 3870047 T11986 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> 3870095 T12024 oasc.ZkController.register We are http://127.0.0.1:26648/_sd/ya/collection1/ and leader is http://127.0.0.1:26648/_sd/ya/collection1/
[junit4] 2> 3870096 T12024 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:26648/_sd/ya
[junit4] 2> 3870096 T12024 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 3870096 T12024 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 3870096 T12024 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3870097 T11979 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3870097 T12024 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3870098 T11976 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3870099 T11976 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:26648/_sd/ya",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:26648__sd%2Fya",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 3870202 T12019 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> 3870202 T11979 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> 3870202 T12000 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> 3870202 T11986 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> 3871236 T11953 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 3871237 T11953 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 3871240 T11953 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:14563
[junit4] 2> 3871240 T11953 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 3871241 T11953 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 3871241 T11953 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hud
[...truncated too long message...]
dPulsing41), 5grand3_s=PostingsFormat(name=Direct), 7grand6_s=PostingsFormat(name=MockRandom), 48parent_f1_s=PostingsFormat(name=Direct), 36parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 4grand2_s=PostingsFormat(name=FSTOrdPulsing41), 7grand4_s=Lucene41(blocksize=128), 44parent_f2_s=Lucene41(blocksize=128), 7grand1_s=PostingsFormat(name=Direct), 2grand1_s=Lucene41(blocksize=128), 16parent_f1_s=Lucene41(blocksize=128), 9parent_f1_s=Lucene41(blocksize=128), 11parent_f2_s=Lucene41(blocksize=128), 23parent_f1_s=PostingsFormat(name=MockRandom), 35parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 3child0_s=Lucene41(blocksize=128), 15parent_f2_s=Lucene41(blocksize=128), 44parent_f1_s=PostingsFormat(name=Direct), 47parent_f1_s=Lucene41(blocksize=128), 3grand2_s=PostingsFormat(name=MockRandom), 4child2_s=PostingsFormat(name=FSTOrdPulsing41), 46parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 24parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 0parent_f1_s=PostingsFormat(name=Direct), 20parent_f2_s=PostingsFormat(name=MockRandom), 7parent_f1_s=PostingsFormat(name=MockRandom), 7grand5_s=PostingsFormat(name=Direct), 48parent_f2_s=Lucene41(blocksize=128), _version_=PostingsFormat(name=FSTOrdPulsing41), 23parent_f2_s=PostingsFormat(name=Direct), 2child0_s=PostingsFormat(name=FSTOrdPulsing41), 16parent_f2_s=PostingsFormat(name=Direct), 21parent_f1_s=Lucene41(blocksize=128), 19parent_f2_s=PostingsFormat(name=MockRandom), 38parent_f2_s=PostingsFormat(name=Direct), 31parent_f2_s=PostingsFormat(name=MockRandom), 51parent_f1_s=PostingsFormat(name=Direct), 5parent_f2_s=PostingsFormat(name=Direct), _root_=PostingsFormat(name=FSTOrdPulsing41), 17parent_f2_s=Lucene41(blocksize=128), 50parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 40parent_f1_s=PostingsFormat(name=Direct), 7grand0_s=Lucene41(blocksize=128), 18parent_f1_s=PostingsFormat(name=MockRandom), 4grand0_s=PostingsFormat(name=Direct), 54parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 28parent_f2_s=Lucene41(blocksize=128), 53parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 6grand4_s=PostingsFormat(name=FSTOrdPulsing41), 22parent_f2_s=Lucene41(blocksize=128), 2grand0_s=PostingsFormat(name=FSTOrdPulsing41), 37parent_f1_s=PostingsFormat(name=Direct), 53parent_f2_s=PostingsFormat(name=MockRandom), 49parent_f2_s=PostingsFormat(name=Direct), 24parent_f2_s=PostingsFormat(name=MockRandom), 33parent_f2_s=Lucene41(blocksize=128), 34parent_f1_s=PostingsFormat(name=MockRandom), 34parent_f2_s=PostingsFormat(name=Direct), 27parent_f2_s=PostingsFormat(name=Direct), 2child1_s=PostingsFormat(name=MockRandom), 3parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 30parent_f1_s=PostingsFormat(name=MockRandom), 39parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 11parent_f1_s=PostingsFormat(name=Direct), 4child3_s=Lucene41(blocksize=128), 4child0_s=PostingsFormat(name=Direct), 49parent_f1_s=PostingsFormat(name=MockRandom), 14parent_f1_s=Lucene41(blocksize=128), 14parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 32parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 41parent_f1_s=PostingsFormat(name=MockRandom), 9parent_f2_s=PostingsFormat(name=Direct), 29parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 19parent_f1_s=PostingsFormat(name=Direct), 2parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 27parent_f1_s=PostingsFormat(name=MockRandom), 54parent_f1_s=Lucene41(blocksize=128), 18parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 1parent_f1_s=Lucene41(blocksize=128), 40parent_f2_s=Lucene41(blocksize=128), 7parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 5grand2_s=Lucene41(blocksize=128), 51parent_f2_s=Lucene41(blocksize=128), 12parent_f2_s=PostingsFormat(name=Direct), 5grand1_s=PostingsFormat(name=FSTOrdPulsing41), 22parent_f1_s=PostingsFormat(name=Direct), 3grand1_s=PostingsFormat(name=Direct), type_s=PostingsFormat(name=FSTOrdPulsing41), 50parent_f1_s=Lucene41(blocksize=128), 13parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 43parent_f1_s=Lucene41(blocksize=128), 6parent_f2_s=Lucene41(blocksize=128), 46parent_f2_s=PostingsFormat(name=MockRandom), 28parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 1grand0_s=Lucene41(blocksize=128), 4parent_f1_s=PostingsFormat(name=Direct), 8parent_f2_s=PostingsFormat(name=MockRandom), 3parent_f1_s=PostingsFormat(name=MockRandom), 31parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 4child1_s=PostingsFormat(name=MockRandom), 42parent_f2_s=PostingsFormat(name=MockRandom), 38parent_f1_s=PostingsFormat(name=MockRandom), 6parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 30parent_f2_s=PostingsFormat(name=Direct), 6grand0_s=PostingsFormat(name=FSTOrdPulsing41), 5grand4_s=PostingsFormat(name=MockRandom), 4grand3_s=PostingsFormat(name=MockRandom), 33parent_f1_s=PostingsFormat(name=Direct), 6grand1_s=PostingsFormat(name=MockRandom), 1parent_f2_s=PostingsFormat(name=Direct), 45parent_f1_s=PostingsFormat(name=MockRandom), 29parent_f1_s=PostingsFormat(name=MockRandom), 39parent_f2_s=PostingsFormat(name=MockRandom), 4parent_f2_s=PostingsFormat(name=MockRandom), 32parent_f1_s=Lucene41(blocksize=128), 10parent_f1_s=Lucene41(blocksize=128), 35parent_f2_s=PostingsFormat(name=MockRandom), 37parent_f2_s=Lucene41(blocksize=128), 25parent_f1_s=Lucene41(blocksize=128), 7grand3_s=PostingsFormat(name=FSTOrdPulsing41), 21parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 36parent_f1_s=Lucene41(blocksize=128), text_t=PostingsFormat(name=FSTOrdPulsing41), 17parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 13parent_f2_s=PostingsFormat(name=MockRandom), 3child2_s=PostingsFormat(name=MockRandom), 4grand1_s=Lucene41(blocksize=128), rnd_b=PostingsFormat(name=MockRandom)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=en_IN, timezone=Antarctica/Syowa
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=16,threads=1,free=211459184,total=477102080
[junit4] 2> NOTE: All tests run in this JVM: [TestBadConfig, SampleTest, TestCursorMarkWithoutUniqueKey, HdfsRecoveryZkTest, DistributedQueryElevationComponentTest, TermVectorComponentDistributedTest, TestMultiCoreConfBootstrap, SSLMigrationTest, TestDynamicFieldCollectionResource, TestMissingGroups, TestNoOpRegenerator, HttpPartitionTest, DistributedSuggestComponentTest, CacheHeaderTest, TestSweetSpotSimilarityFactory, TestElisionMultitermQuery, AutoCommitTest, TestWriterPerf, SearchHandlerTest, TestFiltering, SOLR749Test, SuggesterFSTTest, TestLMDirichletSimilarityFactory, TestDistributedGrouping, TestUpdate, TestSolrQueryParser, TestManagedSchemaFieldResource, MultiTermTest, HardAutoCommitTest, AnalysisErrorHandlingTest, SoftAutoCommitTest, TestFastWriter, DistributedQueryComponentCustomSortTest, ChaosMonkeyNothingIsSafeTest, LukeRequestHandlerTest, TestPseudoReturnFields, OpenCloseCoreStressTest, DocValuesTest, CircularListTest, LegacyHTMLStripCharFilterTest, DistributedQueryComponentOptimizationTest, BasicDistributedZk2Test, RequestHandlersTest, DocValuesMissingTest, TestDocBasedVersionConstraints, TestQueryUtils, TestValueSourceCache, TestIndexingPerformance, DefaultValueUpdateProcessorTest, TestCSVResponseWriter, ResponseHeaderTest, TestReversedWildcardFilterFactory, CopyFieldTest, ClusterStateTest, HdfsLockFactoryTest, TestRecoveryHdfs, TestCollationFieldDocValues, AddBlockUpdateTest, DOMUtilTest, TestImplicitCoreProperties, BinaryUpdateRequestHandlerTest, TestSolr4Spatial2, TestSystemIdResolver, TestFieldCollectionResource, TestGroupingSearch, TestFastLRUCache, TestInfoStreamLogging, QueryParsingTest, InfoHandlerTest, ZkSolrClientTest, AnalyticsMergeStrategyTest, TestJoin, UniqFieldsUpdateProcessorFactoryTest, TestPerFieldSimilarity, OutputWriterTest, TestPHPSerializedResponseWriter, DirectUpdateHandlerOptimizeTest, TimeZoneUtilsTest, PrimUtilsTest, TestConfigSets, TestIndexSearcher, TestFieldSortValues, ShardSplitTest, DocExpirationUpdateProcessorFactoryTest, TestSerializedLuceneMatchVersion, CoreContainerCoreInitFailuresTest, DeleteReplicaTest, TestStressLucene, EnumFieldTest, TestRandomFaceting, TestCloudInspectUtil, TestAtomicUpdateErrorCases, DistributedTermsComponentTest, TestBlendedInfixSuggestions, TestZkChroot, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest, SyncSliceTest, LeaderElectionIntegrationTest, BasicZkTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest]
[junit4] Completed on J1 in 141.49s, 1 test, 1 error <<< FAILURES!
[...truncated 650 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:481: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:454: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/common-build.xml:496: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1299: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:923: There were test failures: 410 suites, 1711 tests, 1 error, 50 ignored (8 assumptions)
Total time: 286 minutes 41 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-NightlyTests-4.x #586
Archived 3 artifacts
Archive block size is 32768
Received 0 blocks and 461190114 bytes
Compression is 0.0%
Took 1 min 15 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
Re: [JENKINS] Lucene-Solr-NightlyTests-4.x - Build # 594 - Still Failing
Posted by Michael McCandless <lu...@mikemccandless.com>.
I committed a fix ...
Mike McCandless
http://blog.mikemccandless.com
On Sat, Aug 9, 2014 at 11:39 AM, Apache Jenkins Server
<je...@builds.apache.org> wrote:
> Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/594/
>
> 1 tests failed.
> REGRESSION: org.apache.lucene.index.TestFlushByRamOrCountsPolicy.testFlushDocCount
>
> Error Message:
> Captured an uncaught exception in thread: Thread[id=3560, name=Thread-2881, state=RUNNABLE, group=TGRP-TestFlushByRamOrCountsPolicy]
>
> Stack Trace:
> com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3560, name=Thread-2881, state=RUNNABLE, group=TGRP-TestFlushByRamOrCountsPolicy]
> Caused by: java.lang.RuntimeException: java.lang.IllegalArgumentException: Document contains at least one immense term in field="body" (whose UTF8 encoding is longer than the max length 32766), all of which were skipped. Please correct the analyzer to not produce such terms. The prefix of the first immense term is: '[125, 125, 123, 123, 123, 123, 123, 115, 117, 98, 115, 116, 99, 124, 125, 125, 125, 123, 123, 123, 49, 125, 125, 125, 124, 123, 123, 123, 112, 49]...', original message: bytes can be at most 32766 in length; got 94384
> at __randomizedtesting.SeedInfo.seed([A89700DEDEDF8395]:0)
> at org.apache.lucene.index.TestFlushByRamOrCountsPolicy$IndexThread.run(TestFlushByRamOrCountsPolicy.java:331)
> Caused by: java.lang.IllegalArgumentException: Document contains at least one immense term in field="body" (whose UTF8 encoding is longer than the max length 32766), all of which were skipped. Please correct the analyzer to not produce such terms. The prefix of the first immense term is: '[125, 125, 123, 123, 123, 123, 123, 115, 117, 98, 115, 116, 99, 124, 125, 125, 125, 123, 123, 123, 49, 125, 125, 125, 124, 123, 123, 123, 112, 49]...', original message: bytes can be at most 32766 in length; got 94384
> at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:671)
> at org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:342)
> at org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:301)
> at org.apache.lucene.index.DocumentsWriterPerThread.updateDocument(DocumentsWriterPerThread.java:241)
> at org.apache.lucene.index.DocumentsWriter.updateDocument(DocumentsWriter.java:451)
> at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1539)
> at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1254)
> at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1235)
> at org.apache.lucene.index.TestFlushByRamOrCountsPolicy$IndexThread.run(TestFlushByRamOrCountsPolicy.java:316)
> Caused by: org.apache.lucene.util.BytesRefHash$MaxBytesLengthExceededException: bytes can be at most 32766 in length; got 94384
> at org.apache.lucene.util.BytesRefHash.add(BytesRefHash.java:284)
> at org.apache.lucene.index.TermsHashPerField.add(TermsHashPerField.java:151)
> at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:645)
> ... 8 more
> Suppressed: java.lang.AssertionError: close() called in wrong state: INCREMENT
> at org.apache.lucene.analysis.MockTokenizer.close(MockTokenizer.java:262)
> at org.apache.lucene.analysis.TokenFilter.close(TokenFilter.java:58)
> at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:661)
> ... 8 more
>
>
>
>
> Build Log:
> [...truncated 1120 lines...]
> [junit4] Suite: org.apache.lucene.index.TestFlushByRamOrCountsPolicy
> [junit4] 1> FAILED exc:
> [junit4] 1> java.lang.IllegalArgumentException: Document contains at least one immense term in field="body" (whose UTF8 encoding is longer than the max length 32766), all of which were skipped. Please correct the analyzer to not produce such terms. The prefix of the first immense term is: '[125, 125, 123, 123, 123, 123, 123, 115, 117, 98, 115, 116, 99, 124, 125, 125, 125, 123, 123, 123, 49, 125, 125, 125, 124, 123, 123, 123, 112, 49]...', original message: bytes can be at most 32766 in length; got 94384
> [junit4] 1> at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:671)
> [junit4] 1> at org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:342)
> [junit4] 1> at org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:301)
> [junit4] 1> at org.apache.lucene.index.DocumentsWriterPerThread.updateDocument(DocumentsWriterPerThread.java:241)
> [junit4] 1> at org.apache.lucene.index.DocumentsWriter.updateDocument(DocumentsWriter.java:451)
> [junit4] 1> at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1539)
> [junit4] 1> at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1254)
> [junit4] 1> at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1235)
> [junit4] 1> at org.apache.lucene.index.TestFlushByRamOrCountsPolicy$IndexThread.run(TestFlushByRamOrCountsPolicy.java:316)
> [junit4] 1> Caused by: org.apache.lucene.util.BytesRefHash$MaxBytesLengthExceededException: bytes can be at most 32766 in length; got 94384
> [junit4] 1> at org.apache.lucene.util.BytesRefHash.add(BytesRefHash.java:284)
> [junit4] 1> at org.apache.lucene.index.TermsHashPerField.add(TermsHashPerField.java:151)
> [junit4] 1> at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:645)
> [junit4] 1> ... 8 more
> [junit4] 1> Suppressed: java.lang.AssertionError: close() called in wrong state: INCREMENT
> [junit4] 1> at org.apache.lucene.analysis.MockTokenizer.close(MockTokenizer.java:262)
> [junit4] 1> at org.apache.lucene.analysis.TokenFilter.close(TokenFilter.java:58)
> [junit4] 1> at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:661)
> [junit4] 1> ... 8 more
> [junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
> [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestFlushByRamOrCountsPolicy -Dtests.method=testFlushDocCount -Dtests.seed=A89700DEDEDF8395 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=es_EC -Dtests.timezone=US/Michigan -Dtests.file.encoding=US-ASCII
> [junit4] ERROR 0.54s J0 | TestFlushByRamOrCountsPolicy.testFlushDocCount <<<
> [junit4] > Throwable #1: java.lang.AssertionError: expected:<170> but was:<101>
> [junit4] > at org.apache.lucene.index.TestFlushByRamOrCountsPolicy.testFlushDocCount(TestFlushByRamOrCountsPolicy.java:160)
> [junit4] > at java.lang.Thread.run(Thread.java:745)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3560, name=Thread-2881, state=RUNNABLE, group=TGRP-TestFlushByRamOrCountsPolicy]
> [junit4] > Caused by: java.lang.RuntimeException: java.lang.IllegalArgumentException: Document contains at least one immense term in field="body" (whose UTF8 encoding is longer than the max length 32766), all of which were skipped. Please correct the analyzer to not produce such terms. The prefix of the first immense term is: '[125, 125, 123, 123, 123, 123, 123, 115, 117, 98, 115, 116, 99, 124, 125, 125, 125, 123, 123, 123, 49, 125, 125, 125, 124, 123, 123, 123, 112, 49]...', original message: bytes can be at most 32766 in length; got 94384
> [junit4] > at __randomizedtesting.SeedInfo.seed([A89700DEDEDF8395]:0)
> [junit4] > at org.apache.lucene.index.TestFlushByRamOrCountsPolicy$IndexThread.run(TestFlushByRamOrCountsPolicy.java:331)
> [junit4] > Caused by: java.lang.IllegalArgumentException: Document contains at least one immense term in field="body" (whose UTF8 encoding is longer than the max length 32766), all of which were skipped. Please correct the analyzer to not produce such terms. The prefix of the first immense term is: '[125, 125, 123, 123, 123, 123, 123, 115, 117, 98, 115, 116, 99, 124, 125, 125, 125, 123, 123, 123, 49, 125, 125, 125, 124, 123, 123, 123, 112, 49]...', original message: bytes can be at most 32766 in length; got 94384
> [junit4] > at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:671)
> [junit4] > at org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:342)
> [junit4] > at org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:301)
> [junit4] > at org.apache.lucene.index.DocumentsWriterPerThread.updateDocument(DocumentsWriterPerThread.java:241)
> [junit4] > at org.apache.lucene.index.DocumentsWriter.updateDocument(DocumentsWriter.java:451)
> [junit4] > at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1539)
> [junit4] > at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1254)
> [junit4] > at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1235)
> [junit4] > at org.apache.lucene.index.TestFlushByRamOrCountsPolicy$IndexThread.run(TestFlushByRamOrCountsPolicy.java:316)
> [junit4] > Caused by: org.apache.lucene.util.BytesRefHash$MaxBytesLengthExceededException: bytes can be at most 32766 in length; got 94384
> [junit4] > at org.apache.lucene.util.BytesRefHash.add(BytesRefHash.java:284)
> [junit4] > at org.apache.lucene.index.TermsHashPerField.add(TermsHashPerField.java:151)
> [junit4] > at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:645)
> [junit4] > ... 8 more
> [junit4] > Suppressed: java.lang.AssertionError: close() called in wrong state: INCREMENT
> [junit4] > at org.apache.lucene.analysis.MockTokenizer.close(MockTokenizer.java:262)
> [junit4] > at org.apache.lucene.analysis.TokenFilter.close(TokenFilter.java:58)
> [junit4] > at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:661)
> [junit4] > ... 8 more
> [junit4] 2> NOTE: leaving temporary files on disk at: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/build/core/test/J0/./lucene.index.TestFlushByRamOrCountsPolicy-A89700DEDEDF8395-001
> [junit4] 2> NOTE: test params are: codec=Lucene49: {titleTokenized=PostingsFormat(name=Memory doPackFST= false), date=Pulsing41(freqCutoff=9 minBlockSize=35 maxBlockSize=138), body=Pulsing41(freqCutoff=9 minBlockSize=35 maxBlockSize=138), title=Pulsing41(freqCutoff=15 minBlockSize=35 maxBlockSize=138), docid=FSTOrd41}, docValues:{titleDV=DocValuesFormat(name=Memory)}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {titleTokenized=DFR G1, body=DFR I(n)L1}, locale=es_EC, timezone=US/Michigan
> [junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=16,threads=1,free=213787512,total=457703424
> [junit4] 2> NOTE: All tests run in this JVM: [TestSimilarityProvider, TestSearch, TestLockFactory, TestIndexWriterCommit, TestLazyProxSkipping, TestCompiledAutomaton, TestTermsEnum, ThrowInUncaught, TestFilteredSearch, TestSloppyPhraseQuery, TestScoreCachingWrappingScorer, TestNumericDocValuesUpdates, TestAllFilesHaveCodecHeader, TestDemo, TestNoDeletionPolicy, TestCharTermAttributeImpl, TestMultiValuedNumericRangeQuery, TestNearSpansOrdered, TestDeletionPolicy, TestBytesStore, TestScorerPerf, Nested, Nested, TestOmitPositions, TestDocTermOrdsRewriteMethod, TestFieldsReader, TestTwoPhaseCommitTool, TestSearcherManager, TestNoMergeScheduler, TestSortRescorer, TestDoc, TestQueryWrapperFilter, TestSearchAfter, TestSort, Test2BPostings, TestFieldCacheRewriteMethod, TestLock, TestSimpleAttributeImpl, TestVirtualMethod, TestBufferedChecksum, TestBytesRef, TestFieldReuse, TestPForDeltaDocIdSet, TestIndexableBinaryStringTools, TestIndexableField, TestEarlyTermination, TestPriorityQueue, TestIndexSearcher, TestPerSegmentDeletes, TestMultiPhraseQuery, TestIndexWriterReader, TestNumericRangeQuery32, TestLucene42DocValuesFormat, TestDocValuesWithThreads, TestLookaheadTokenFilter, TestForceMergeForever, TestIndexCommit, TestTermScorer, Test2BBinaryDocValues, TestIndexWriterConfig, TestIntroSorter, TestLiveFieldValues, TestPrefixRandom, TestMathUtil, TestMultiTermQueryRewrites, TestSpans, TestBagOfPostings, TestTermsEnum2, TestFastDecompressionMode, TestFilterIterator, TestIndexWriterExceptions2, TestStoredFieldsFormat, TestSentinelIntSet, TestTopScoreDocCollector, TestStressNRT, TestReuseDocsEnum, TestMergeSchedulerExternal, Test2BPostingsBytes, TestDocIdBitSet, TestIndexReaderClose, TestExceedMaxTermLength, TestTerms, TestPersistentSnapshotDeletionPolicy, TestPhraseQuery, TestUTF32ToUTF8, TestComplexExplanations, TestLucene45DocValuesFormat, TestSpanExplanations, TestQueryRescorer, TestTopDocsCollector, TestTopFieldCollector, TestReusableStringReader, TestSetOnce, Test2BPagedBytes, TestPostingsFormat, TestPhrasePrefixQuery, TestBinaryDocValuesUpdates, TestByteSlices, TestCrash, TestLongBitSet, TestTermVectors, TestCompoundFile, TestIndexWriterForceMerge, TestIndexWriterLockRelease, TestPayloadsOnVectors, TestRecyclingByteBlockAllocator, TestBlockPostingsFormat3, TestFlushByRamOrCountsPolicy]
> [junit4] Completed on J0 in 10.63s, 5 tests, 1 error <<< FAILURES!
>
> [...truncated 719 lines...]
> BUILD FAILED
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:481: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:454: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:45: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/extra-targets.xml:37: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/build.xml:49: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1299: The following error occurred while executing this line:
> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:923: There were test failures: 417 suites, 3600 tests, 1 error, 129 ignored (118 assumptions)
>
> Total time: 88 minutes 55 seconds
> Build step 'Invoke Ant' marked build as failure
> Archiving artifacts
> Sending artifact delta relative to Lucene-Solr-NightlyTests-4.x #586
> Archived 3 artifacts
> Archive block size is 32768
> Received 0 blocks and 4826209 bytes
> Compression is 0.0%
> Took 3.1 sec
> Recording test results
> Email was triggered for: Failure
> Sending email for trigger: Failure
>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
[JENKINS] Lucene-Solr-NightlyTests-4.x - Build # 594 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/594/
1 tests failed.
REGRESSION: org.apache.lucene.index.TestFlushByRamOrCountsPolicy.testFlushDocCount
Error Message:
Captured an uncaught exception in thread: Thread[id=3560, name=Thread-2881, state=RUNNABLE, group=TGRP-TestFlushByRamOrCountsPolicy]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3560, name=Thread-2881, state=RUNNABLE, group=TGRP-TestFlushByRamOrCountsPolicy]
Caused by: java.lang.RuntimeException: java.lang.IllegalArgumentException: Document contains at least one immense term in field="body" (whose UTF8 encoding is longer than the max length 32766), all of which were skipped. Please correct the analyzer to not produce such terms. The prefix of the first immense term is: '[125, 125, 123, 123, 123, 123, 123, 115, 117, 98, 115, 116, 99, 124, 125, 125, 125, 123, 123, 123, 49, 125, 125, 125, 124, 123, 123, 123, 112, 49]...', original message: bytes can be at most 32766 in length; got 94384
at __randomizedtesting.SeedInfo.seed([A89700DEDEDF8395]:0)
at org.apache.lucene.index.TestFlushByRamOrCountsPolicy$IndexThread.run(TestFlushByRamOrCountsPolicy.java:331)
Caused by: java.lang.IllegalArgumentException: Document contains at least one immense term in field="body" (whose UTF8 encoding is longer than the max length 32766), all of which were skipped. Please correct the analyzer to not produce such terms. The prefix of the first immense term is: '[125, 125, 123, 123, 123, 123, 123, 115, 117, 98, 115, 116, 99, 124, 125, 125, 125, 123, 123, 123, 49, 125, 125, 125, 124, 123, 123, 123, 112, 49]...', original message: bytes can be at most 32766 in length; got 94384
at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:671)
at org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:342)
at org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:301)
at org.apache.lucene.index.DocumentsWriterPerThread.updateDocument(DocumentsWriterPerThread.java:241)
at org.apache.lucene.index.DocumentsWriter.updateDocument(DocumentsWriter.java:451)
at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1539)
at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1254)
at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1235)
at org.apache.lucene.index.TestFlushByRamOrCountsPolicy$IndexThread.run(TestFlushByRamOrCountsPolicy.java:316)
Caused by: org.apache.lucene.util.BytesRefHash$MaxBytesLengthExceededException: bytes can be at most 32766 in length; got 94384
at org.apache.lucene.util.BytesRefHash.add(BytesRefHash.java:284)
at org.apache.lucene.index.TermsHashPerField.add(TermsHashPerField.java:151)
at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:645)
... 8 more
Suppressed: java.lang.AssertionError: close() called in wrong state: INCREMENT
at org.apache.lucene.analysis.MockTokenizer.close(MockTokenizer.java:262)
at org.apache.lucene.analysis.TokenFilter.close(TokenFilter.java:58)
at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:661)
... 8 more
Build Log:
[...truncated 1120 lines...]
[junit4] Suite: org.apache.lucene.index.TestFlushByRamOrCountsPolicy
[junit4] 1> FAILED exc:
[junit4] 1> java.lang.IllegalArgumentException: Document contains at least one immense term in field="body" (whose UTF8 encoding is longer than the max length 32766), all of which were skipped. Please correct the analyzer to not produce such terms. The prefix of the first immense term is: '[125, 125, 123, 123, 123, 123, 123, 115, 117, 98, 115, 116, 99, 124, 125, 125, 125, 123, 123, 123, 49, 125, 125, 125, 124, 123, 123, 123, 112, 49]...', original message: bytes can be at most 32766 in length; got 94384
[junit4] 1> at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:671)
[junit4] 1> at org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:342)
[junit4] 1> at org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:301)
[junit4] 1> at org.apache.lucene.index.DocumentsWriterPerThread.updateDocument(DocumentsWriterPerThread.java:241)
[junit4] 1> at org.apache.lucene.index.DocumentsWriter.updateDocument(DocumentsWriter.java:451)
[junit4] 1> at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1539)
[junit4] 1> at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1254)
[junit4] 1> at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1235)
[junit4] 1> at org.apache.lucene.index.TestFlushByRamOrCountsPolicy$IndexThread.run(TestFlushByRamOrCountsPolicy.java:316)
[junit4] 1> Caused by: org.apache.lucene.util.BytesRefHash$MaxBytesLengthExceededException: bytes can be at most 32766 in length; got 94384
[junit4] 1> at org.apache.lucene.util.BytesRefHash.add(BytesRefHash.java:284)
[junit4] 1> at org.apache.lucene.index.TermsHashPerField.add(TermsHashPerField.java:151)
[junit4] 1> at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:645)
[junit4] 1> ... 8 more
[junit4] 1> Suppressed: java.lang.AssertionError: close() called in wrong state: INCREMENT
[junit4] 1> at org.apache.lucene.analysis.MockTokenizer.close(MockTokenizer.java:262)
[junit4] 1> at org.apache.lucene.analysis.TokenFilter.close(TokenFilter.java:58)
[junit4] 1> at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:661)
[junit4] 1> ... 8 more
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestFlushByRamOrCountsPolicy -Dtests.method=testFlushDocCount -Dtests.seed=A89700DEDEDF8395 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=es_EC -Dtests.timezone=US/Michigan -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.54s J0 | TestFlushByRamOrCountsPolicy.testFlushDocCount <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<170> but was:<101>
[junit4] > at org.apache.lucene.index.TestFlushByRamOrCountsPolicy.testFlushDocCount(TestFlushByRamOrCountsPolicy.java:160)
[junit4] > at java.lang.Thread.run(Thread.java:745)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3560, name=Thread-2881, state=RUNNABLE, group=TGRP-TestFlushByRamOrCountsPolicy]
[junit4] > Caused by: java.lang.RuntimeException: java.lang.IllegalArgumentException: Document contains at least one immense term in field="body" (whose UTF8 encoding is longer than the max length 32766), all of which were skipped. Please correct the analyzer to not produce such terms. The prefix of the first immense term is: '[125, 125, 123, 123, 123, 123, 123, 115, 117, 98, 115, 116, 99, 124, 125, 125, 125, 123, 123, 123, 49, 125, 125, 125, 124, 123, 123, 123, 112, 49]...', original message: bytes can be at most 32766 in length; got 94384
[junit4] > at __randomizedtesting.SeedInfo.seed([A89700DEDEDF8395]:0)
[junit4] > at org.apache.lucene.index.TestFlushByRamOrCountsPolicy$IndexThread.run(TestFlushByRamOrCountsPolicy.java:331)
[junit4] > Caused by: java.lang.IllegalArgumentException: Document contains at least one immense term in field="body" (whose UTF8 encoding is longer than the max length 32766), all of which were skipped. Please correct the analyzer to not produce such terms. The prefix of the first immense term is: '[125, 125, 123, 123, 123, 123, 123, 115, 117, 98, 115, 116, 99, 124, 125, 125, 125, 123, 123, 123, 49, 125, 125, 125, 124, 123, 123, 123, 112, 49]...', original message: bytes can be at most 32766 in length; got 94384
[junit4] > at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:671)
[junit4] > at org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:342)
[junit4] > at org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:301)
[junit4] > at org.apache.lucene.index.DocumentsWriterPerThread.updateDocument(DocumentsWriterPerThread.java:241)
[junit4] > at org.apache.lucene.index.DocumentsWriter.updateDocument(DocumentsWriter.java:451)
[junit4] > at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1539)
[junit4] > at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1254)
[junit4] > at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1235)
[junit4] > at org.apache.lucene.index.TestFlushByRamOrCountsPolicy$IndexThread.run(TestFlushByRamOrCountsPolicy.java:316)
[junit4] > Caused by: org.apache.lucene.util.BytesRefHash$MaxBytesLengthExceededException: bytes can be at most 32766 in length; got 94384
[junit4] > at org.apache.lucene.util.BytesRefHash.add(BytesRefHash.java:284)
[junit4] > at org.apache.lucene.index.TermsHashPerField.add(TermsHashPerField.java:151)
[junit4] > at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:645)
[junit4] > ... 8 more
[junit4] > Suppressed: java.lang.AssertionError: close() called in wrong state: INCREMENT
[junit4] > at org.apache.lucene.analysis.MockTokenizer.close(MockTokenizer.java:262)
[junit4] > at org.apache.lucene.analysis.TokenFilter.close(TokenFilter.java:58)
[junit4] > at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:661)
[junit4] > ... 8 more
[junit4] 2> NOTE: leaving temporary files on disk at: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/build/core/test/J0/./lucene.index.TestFlushByRamOrCountsPolicy-A89700DEDEDF8395-001
[junit4] 2> NOTE: test params are: codec=Lucene49: {titleTokenized=PostingsFormat(name=Memory doPackFST= false), date=Pulsing41(freqCutoff=9 minBlockSize=35 maxBlockSize=138), body=Pulsing41(freqCutoff=9 minBlockSize=35 maxBlockSize=138), title=Pulsing41(freqCutoff=15 minBlockSize=35 maxBlockSize=138), docid=FSTOrd41}, docValues:{titleDV=DocValuesFormat(name=Memory)}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {titleTokenized=DFR G1, body=DFR I(n)L1}, locale=es_EC, timezone=US/Michigan
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=16,threads=1,free=213787512,total=457703424
[junit4] 2> NOTE: All tests run in this JVM: [TestSimilarityProvider, TestSearch, TestLockFactory, TestIndexWriterCommit, TestLazyProxSkipping, TestCompiledAutomaton, TestTermsEnum, ThrowInUncaught, TestFilteredSearch, TestSloppyPhraseQuery, TestScoreCachingWrappingScorer, TestNumericDocValuesUpdates, TestAllFilesHaveCodecHeader, TestDemo, TestNoDeletionPolicy, TestCharTermAttributeImpl, TestMultiValuedNumericRangeQuery, TestNearSpansOrdered, TestDeletionPolicy, TestBytesStore, TestScorerPerf, Nested, Nested, TestOmitPositions, TestDocTermOrdsRewriteMethod, TestFieldsReader, TestTwoPhaseCommitTool, TestSearcherManager, TestNoMergeScheduler, TestSortRescorer, TestDoc, TestQueryWrapperFilter, TestSearchAfter, TestSort, Test2BPostings, TestFieldCacheRewriteMethod, TestLock, TestSimpleAttributeImpl, TestVirtualMethod, TestBufferedChecksum, TestBytesRef, TestFieldReuse, TestPForDeltaDocIdSet, TestIndexableBinaryStringTools, TestIndexableField, TestEarlyTermination, TestPriorityQueue, TestIndexSearcher, TestPerSegmentDeletes, TestMultiPhraseQuery, TestIndexWriterReader, TestNumericRangeQuery32, TestLucene42DocValuesFormat, TestDocValuesWithThreads, TestLookaheadTokenFilter, TestForceMergeForever, TestIndexCommit, TestTermScorer, Test2BBinaryDocValues, TestIndexWriterConfig, TestIntroSorter, TestLiveFieldValues, TestPrefixRandom, TestMathUtil, TestMultiTermQueryRewrites, TestSpans, TestBagOfPostings, TestTermsEnum2, TestFastDecompressionMode, TestFilterIterator, TestIndexWriterExceptions2, TestStoredFieldsFormat, TestSentinelIntSet, TestTopScoreDocCollector, TestStressNRT, TestReuseDocsEnum, TestMergeSchedulerExternal, Test2BPostingsBytes, TestDocIdBitSet, TestIndexReaderClose, TestExceedMaxTermLength, TestTerms, TestPersistentSnapshotDeletionPolicy, TestPhraseQuery, TestUTF32ToUTF8, TestComplexExplanations, TestLucene45DocValuesFormat, TestSpanExplanations, TestQueryRescorer, TestTopDocsCollector, TestTopFieldCollector, TestReusableStringReader, TestSetOnce, Test2BPagedBytes, TestPostingsFormat, TestPhrasePrefixQuery, TestBinaryDocValuesUpdates, TestByteSlices, TestCrash, TestLongBitSet, TestTermVectors, TestCompoundFile, TestIndexWriterForceMerge, TestIndexWriterLockRelease, TestPayloadsOnVectors, TestRecyclingByteBlockAllocator, TestBlockPostingsFormat3, TestFlushByRamOrCountsPolicy]
[junit4] Completed on J0 in 10.63s, 5 tests, 1 error <<< FAILURES!
[...truncated 719 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:481: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:454: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/build.xml:49: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1299: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:923: There were test failures: 417 suites, 3600 tests, 1 error, 129 ignored (118 assumptions)
Total time: 88 minutes 55 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-NightlyTests-4.x #586
Archived 3 artifacts
Archive block size is 32768
Received 0 blocks and 4826209 bytes
Compression is 0.0%
Took 3.1 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure