You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/07/28 21:49:45 UTC
[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.8.0-ea-b99) - Build
# 3084 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3084/
Java: 64bit/jdk1.8.0-ea-b99 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.AliasIntegrationTest.testDistribSearch
Error Message:
Collection not found: testalias
Stack Trace:
org.apache.solr.common.SolrException: Collection not found: testalias
at __randomizedtesting.SeedInfo.seed([A952590066AD228C:28B4D71811F242B0]:0)
at org.apache.solr.client.solrj.impl.CloudSolrServer.getCollectionList(CloudSolrServer.java:338)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:219)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.cloud.AliasIntegrationTest.doTest(AliasIntegrationTest.java:131)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
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:491)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 9714 lines...]
[junit4] Suite: org.apache.solr.cloud.AliasIntegrationTest
[junit4] 2> 582421 T2207 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 582426 T2207 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-AliasIntegrationTest-1375039382703
[junit4] 2> 582429 T2207 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 582460 T2208 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 582530 T2207 oasc.ZkTestServer.run start zk server on port:58070
[junit4] 2> 582532 T2207 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 582540 T2214 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@285f28c9 name:ZooKeeperConnection Watcher:127.0.0.1:58070 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 582540 T2207 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 582541 T2207 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 582556 T2207 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 582561 T2216 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2698c3b2 name:ZooKeeperConnection Watcher:127.0.0.1:58070/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 582561 T2207 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 582561 T2207 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 582571 T2207 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 582575 T2207 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 582581 T2207 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 582585 T2207 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 582587 T2207 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 582594 T2207 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4] 2> 582595 T2207 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 582600 T2207 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 582601 T2207 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 582606 T2207 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 582607 T2207 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 582611 T2207 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4] 2> 582612 T2207 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 582618 T2207 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 582618 T2207 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 582623 T2207 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 582624 T2207 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 582629 T2207 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 582630 T2207 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 582634 T2207 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 582635 T2207 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 582821 T2209 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14026bbe4d60001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2>
[junit4] 2> 583104 T2207 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 583113 T2207 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58077
[junit4] 2> 583113 T2207 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 583113 T2207 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 583113 T2207 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-controljetty-1375039382916
[junit4] 2> 583115 T2207 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-controljetty-1375039382916\'
[junit4] 2> 583142 T2207 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-controljetty-1375039382916\solr.xml
[junit4] 2> 583155 T2207 oasc.CoreContainer.<init> New CoreContainer 2094496128
[junit4] 2> 583155 T2207 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-controljetty-1375039382916\]
[junit4] 2> 583157 T2207 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 583157 T2207 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 583157 T2207 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 583157 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 583158 T2207 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 583158 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 583158 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 583158 T2207 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 583158 T2207 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 583158 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 583168 T2207 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58070/solr
[junit4] 2> 583168 T2207 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 583170 T2207 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 583198 T2227 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58438f48 name:ZooKeeperConnection Watcher:127.0.0.1:58070 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 583198 T2207 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 583204 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 583211 T2207 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 583216 T2229 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@62d37664 name:ZooKeeperConnection Watcher:127.0.0.1:58070/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 583217 T2207 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 583221 T2207 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 583227 T2207 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 583233 T2207 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 583236 T2207 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58077_
[junit4] 2> 583238 T2207 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58077_
[junit4] 2> 583246 T2207 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 583257 T2207 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 583261 T2207 oasc.Overseer.start Overseer (id=90114580987379715-127.0.0.1:58077_-n_0000000000) starting
[junit4] 2> 583268 T2207 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 583275 T2231 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 583277 T2207 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 583283 T2207 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 583288 T2207 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 583294 T2230 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 583298 T2232 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 583298 T2232 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 583301 T2232 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 583302 T2230 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 583304 T2230 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:58077_",
[junit4] 2> "base_url":"http://127.0.0.1:58077"}
[junit4] 2> 583304 T2230 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 583304 T2230 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 583315 T2229 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> 584301 T2232 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 584301 T2232 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-controljetty-1375039382916\collection1
[junit4] 2> 584301 T2232 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 584303 T2232 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 584303 T2232 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 584305 T2232 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-controljetty-1375039382916\collection1\'
[junit4] 2> 584306 T2232 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-controljetty-1375039382916/collection1/lib/classes/' to classloader
[junit4] 2> 584307 T2232 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-controljetty-1375039382916/collection1/lib/README' to classloader
[junit4] 2> 584334 T2232 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 584344 T2232 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 584347 T2232 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 584352 T2232 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 584511 T2232 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 584517 T2232 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 584518 T2232 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 584539 T2232 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 584542 T2232 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 584546 T2232 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 584548 T2232 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 584548 T2232 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 584548 T2232 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 584550 T2232 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 584550 T2232 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 584550 T2232 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 584550 T2232 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-controljetty-1375039382916\collection1\, dataDir=.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/control/data\
[junit4] 2> 584550 T2232 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43caf0d8
[junit4] 2> 584551 T2232 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/control/data\
[junit4] 2> 584551 T2232 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/control/data\index/
[junit4] 2> 584551 T2232 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701\control\data\index' doesn't exist. Creating new index...
[junit4] 2> 584552 T2232 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/control/data\index
[junit4] 2> 584557 T2232 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3ca6d8b4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@dff7035),segFN=segments_1,generation=1}
[junit4] 2> 584557 T2232 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 584561 T2232 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 584562 T2232 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 584562 T2232 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 584563 T2232 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 584563 T2232 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 584563 T2232 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 584563 T2232 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 584564 T2232 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 584564 T2232 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 584571 T2232 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 584572 T2232 oass.SolrIndexSearcher.<init> Opening Searcher@458cf067 main
[junit4] 2> 584574 T2232 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 584574 T2232 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 584578 T2232 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 584578 T2232 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58077 collection:control_collection shard:shard1
[junit4] 2> 584578 T2232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 584588 T2232 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 584592 T2233 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@458cf067 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 584627 T2232 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 584634 T2232 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 584634 T2232 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 584634 T2232 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58077/collection1/
[junit4] 2> 584634 T2232 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 584634 T2232 oasc.SyncStrategy.syncToMe http://127.0.0.1:58077/collection1/ has no replicas
[junit4] 2> 584634 T2232 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58077/collection1/ shard1
[junit4] 2> 584635 T2232 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 584822 T2230 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 584838 T2229 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> 584850 T2232 oasc.ZkController.register We are http://127.0.0.1:58077/collection1/ and leader is http://127.0.0.1:58077/collection1/
[junit4] 2> 584850 T2232 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58077
[junit4] 2> 584850 T2232 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 584851 T2232 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 584851 T2232 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 584854 T2232 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 584858 T2207 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 584858 T2207 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 584858 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 584863 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 584866 T2207 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 584871 T2236 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c5db241 name:ZooKeeperConnection Watcher:127.0.0.1:58070/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 584871 T2207 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 584874 T2207 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 584877 T2207 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 585268 T2207 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 585274 T2207 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58089
[junit4] 2> 585274 T2207 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 585274 T2207 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 585275 T2207 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty1-1375039385152
[junit4] 2> 585275 T2207 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty1-1375039385152\'
[junit4] 2> 585318 T2207 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty1-1375039385152\solr.xml
[junit4] 2> 585331 T2207 oasc.CoreContainer.<init> New CoreContainer 1009076561
[junit4] 2> 585331 T2207 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty1-1375039385152\]
[junit4] 2> 585332 T2207 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 585332 T2207 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 585332 T2207 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 585332 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 585333 T2207 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 585333 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 585334 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 585334 T2207 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 585334 T2207 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 585334 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 585342 T2207 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58070/solr
[junit4] 2> 585342 T2207 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 585345 T2207 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 585363 T2247 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73e263a2 name:ZooKeeperConnection Watcher:127.0.0.1:58070 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 585363 T2207 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 585370 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 585377 T2207 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 585383 T2249 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a1561ad name:ZooKeeperConnection Watcher:127.0.0.1:58070/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 585383 T2207 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 585391 T2207 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 586348 T2230 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 586351 T2230 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:58077_",
[junit4] 2> "base_url":"http://127.0.0.1:58077"}
[junit4] 2> 586401 T2207 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58089_
[junit4] 2> 586404 T2207 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58089_
[junit4] 2> 586414 T2229 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 586416 T2236 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 586417 T2249 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 586421 T2236 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> 586421 T2249 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> 586439 T2250 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 586439 T2250 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 586440 T2229 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 586440 T2229 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> 586443 T2250 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 587936 T2230 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 587938 T2230 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:58089_",
[junit4] 2> "base_url":"http://127.0.0.1:58089"}
[junit4] 2> 587938 T2230 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4] 2> 587938 T2230 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 587953 T2249 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> 587953 T2229 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> 587954 T2236 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> 588444 T2250 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 588444 T2250 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty1-1375039385152\collection1
[junit4] 2> 588444 T2250 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 588446 T2250 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 588446 T2250 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 588448 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty1-1375039385152\collection1\'
[junit4] 2> 588449 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty1-1375039385152/collection1/lib/classes/' to classloader
[junit4] 2> 588450 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty1-1375039385152/collection1/lib/README' to classloader
[junit4] 2> 588478 T2250 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 588497 T2250 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 589661 T2250 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 589666 T2250 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 589828 T2250 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 589835 T2250 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 589837 T2250 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 589860 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 589864 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 589868 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 589870 T2250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 589870 T2250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 589870 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 589872 T2250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 589872 T2250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 589872 T2250 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 589873 T2250 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty1-1375039385152\collection1\, dataDir=.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty1\
[junit4] 2> 589873 T2250 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43caf0d8
[junit4] 2> 589874 T2250 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty1\
[junit4] 2> 589874 T2250 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty1\index/
[junit4] 2> 589874 T2250 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701\jetty1\index' doesn't exist. Creating new index...
[junit4] 2> 589874 T2250 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty1\index
[junit4] 2> 589880 T2250 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@21a0cb2e lockFactory=org.apache.lucene.store.NativeFSLockFactory@5eb8c89b),segFN=segments_1,generation=1}
[junit4] 2> 589880 T2250 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 589885 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 589886 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 589886 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 589887 T2250 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 589887 T2250 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 589887 T2250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 589888 T2250 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 589889 T2250 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 589889 T2250 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 589895 T2250 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 589896 T2250 oass.SolrIndexSearcher.<init> Opening Searcher@65e067d4 main
[junit4] 2> 589897 T2250 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 589898 T2250 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 589903 T2250 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 589903 T2250 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58089 collection:collection1 shard:shard1
[junit4] 2> 589903 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 589917 T2250 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 589922 T2251 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@65e067d4 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 589942 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 589952 T2250 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 589952 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 589952 T2250 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58089/collection1/
[junit4] 2> 589952 T2250 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 589953 T2250 oasc.SyncStrategy.syncToMe http://127.0.0.1:58089/collection1/ has no replicas
[junit4] 2> 589953 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58089/collection1/ shard1
[junit4] 2> 589953 T2250 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 591349 T2230 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 591373 T2236 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> 591374 T2249 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> 591375 T2229 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> 591390 T2250 oasc.ZkController.register We are http://127.0.0.1:58089/collection1/ and leader is http://127.0.0.1:58089/collection1/
[junit4] 2> 591390 T2250 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58089
[junit4] 2> 591390 T2250 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 591390 T2250 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 591390 T2250 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 591396 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 591401 T2207 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 591402 T2207 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 591402 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 591915 T2207 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 591921 T2207 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58098
[junit4] 2> 591921 T2207 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 591922 T2207 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 591922 T2207 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty2-1375039391683
[junit4] 2> 591922 T2207 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty2-1375039391683\'
[junit4] 2> 591953 T2207 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty2-1375039391683\solr.xml
[junit4] 2> 591983 T2207 oasc.CoreContainer.<init> New CoreContainer 737159999
[junit4] 2> 591984 T2207 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty2-1375039391683\]
[junit4] 2> 591985 T2207 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 591985 T2207 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 591985 T2207 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 591985 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 591985 T2207 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 591986 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 591986 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 591986 T2207 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 591986 T2207 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 591986 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 591995 T2207 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58070/solr
[junit4] 2> 591995 T2207 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 592004 T2207 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 592024 T2263 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4423e772 name:ZooKeeperConnection Watcher:127.0.0.1:58070 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 592024 T2207 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 592030 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 592045 T2207 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 592051 T2265 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39621f6f name:ZooKeeperConnection Watcher:127.0.0.1:58070/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 592051 T2207 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 592061 T2207 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 592899 T2230 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 592901 T2230 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:58089_",
[junit4] 2> "base_url":"http://127.0.0.1:58089"}
[junit4] 2> 592911 T2236 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> 592912 T2249 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> 592912 T2265 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> 592914 T2229 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> 593067 T2207 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58098_
[junit4] 2> 593070 T2207 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58098_
[junit4] 2> 593076 T2236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 593077 T2265 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 593078 T2229 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 593080 T2249 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 593081 T2249 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 593088 T2236 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 593088 T2265 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 593088 T2229 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 593097 T2266 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 593097 T2266 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 593099 T2266 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 594427 T2230 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 594429 T2230 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:58098_",
[junit4] 2> "base_url":"http://127.0.0.1:58098"}
[junit4] 2> 594429 T2230 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 594429 T2230 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 594445 T2236 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> 594446 T2249 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> 594447 T2265 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> 594447 T2229 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> 595099 T2266 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 595099 T2266 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty2-1375039391683\collection1
[junit4] 2> 595099 T2266 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 595102 T2266 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 595102 T2266 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 595104 T2266 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty2-1375039391683\collection1\'
[junit4] 2> 595107 T2266 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty2-1375039391683/collection1/lib/classes/' to classloader
[junit4] 2> 595109 T2266 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty2-1375039391683/collection1/lib/README' to classloader
[junit4] 2> 595152 T2266 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 595177 T2266 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 595181 T2266 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 595190 T2266 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 595359 T2266 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 595366 T2266 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 595368 T2266 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 595387 T2266 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 595390 T2266 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 595393 T2266 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 595395 T2266 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 595395 T2266 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 595395 T2266 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 595397 T2266 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 595397 T2266 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 595397 T2266 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 595397 T2266 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty2-1375039391683\collection1\, dataDir=.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty2\
[junit4] 2> 595397 T2266 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43caf0d8
[junit4] 2> 595398 T2266 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty2\
[junit4] 2> 595398 T2266 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty2\index/
[junit4] 2> 595398 T2266 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701\jetty2\index' doesn't exist. Creating new index...
[junit4] 2> 595399 T2266 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty2\index
[junit4] 2> 595403 T2266 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b3cea9f lockFactory=org.apache.lucene.store.NativeFSLockFactory@46e19b87),segFN=segments_1,generation=1}
[junit4] 2> 595404 T2266 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 595409 T2266 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 595409 T2266 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 595410 T2266 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 595410 T2266 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 595411 T2266 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 595411 T2266 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 595411 T2266 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 595412 T2266 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 595412 T2266 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 595420 T2266 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 595421 T2266 oass.SolrIndexSearcher.<init> Opening Searcher@79c41fcd main
[junit4] 2> 595422 T2266 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 595422 T2266 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 595428 T2266 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 595428 T2266 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58098 collection:collection1 shard:shard1
[junit4] 2> 595428 T2266 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 595437 T2267 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@79c41fcd main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 595446 T2266 oasc.ZkController.register We are http://127.0.0.1:58098/collection1/ and leader is http://127.0.0.1:58089/collection1/
[junit4] 2> 595446 T2266 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58098
[junit4] 2> 595446 T2266 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 595446 T2266 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C5742 name=collection1 org.apache.solr.core.SolrCore@ea172fb url=http://127.0.0.1:58098/collection1 node=127.0.0.1:58098_ C5742_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:58098_, base_url=http://127.0.0.1:58098}
[junit4] 2> 595447 T2268 C5742 P58098 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 595449 T2268 C5742 P58098 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 595449 T2268 C5742 P58098 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 595449 T2268 C5742 P58098 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 595451 T2266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 595452 T2268 C5742 P58098 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 595460 T2240 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 595461 T2207 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 595462 T2207 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 595462 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 595873 T2207 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 595878 T2207 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58108
[junit4] 2> 595879 T2207 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 595879 T2207 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 595879 T2207 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty3-1375039395742
[junit4] 2> 595879 T2207 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty3-1375039395742\'
[junit4] 2> 595907 T2207 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty3-1375039395742\solr.xml
[junit4] 2> 595920 T2207 oasc.CoreContainer.<init> New CoreContainer 378406761
[junit4] 2> 595920 T2207 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty3-1375039395742\]
[junit4] 2> 595921 T2207 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 595921 T2207 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 595921 T2207 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 595921 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 595922 T2207 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 595922 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 595923 T2207 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 595923 T2207 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 595923 T2207 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 595923 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 595931 T2207 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58070/solr
[junit4] 2> 595932 T2207 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 595936 T2207 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 595959 T2280 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c621d87 name:ZooKeeperConnection Watcher:127.0.0.1:58070 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 595960 T2207 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 595964 T2230 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 595967 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 595973 T2207 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 595977 T2230 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"recovering",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:58098_",
[junit4] 2> "base_url":"http://127.0.0.1:58098"}
[junit4] 2> 595985 T2282 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2921f7c2 name:ZooKeeperConnection Watcher:127.0.0.1:58070/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 595986 T2207 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 595997 T2236 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> 595997 T2249 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> 595998 T2265 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> 595999 T2229 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> 596012 T2207 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 596460 T2240 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 596460 T2240 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node2&state=recovering&nodeName=127.0.0.1:58098_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1000
[junit4] 2> 597015 T2207 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58108_
[junit4] 2> 597018 T2207 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58108_
[junit4] 2> 597023 T2236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 597025 T2265 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 597026 T2229 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 597028 T2282 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 597029 T2249 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 597029 T2249 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 597036 T2236 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 597036 T2265 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 597036 T2229 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 597044 T2283 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 597044 T2283 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 597049 T2283 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 597512 T2230 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 597514 T2230 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:58108_",
[junit4] 2> "base_url":"http://127.0.0.1:58108"}
[junit4] 2> 597514 T2230 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 597514 T2230 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 597523 T2282 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 597524 T2236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 597525 T2249 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 597525 T2265 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 597526 T2229 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 598049 T2283 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 598050 T2283 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty3-1375039395742\collection1
[junit4] 2> 598050 T2283 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 598051 T2283 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 598051 T2283 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 598054 T2283 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty3-1375039395742\collection1\'
[junit4] 2> 598055 T2283 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty3-1375039395742/collection1/lib/classes/' to classloader
[junit4] 2> 598056 T2283 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty3-1375039395742/collection1/lib/README' to classloader
[junit4] 2> 598095 T2283 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 598103 T2283 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 598108 T2283 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 598114 T2283 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 598278 T2283 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 598285 T2283 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 598286 T2283 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 598305 T2283 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 598307 T2283 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 598311 T2283 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 598312 T2283 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 598312 T2283 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 598312 T2283 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 598315 T2283 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 598315 T2283 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 598315 T2283 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 598315 T2283 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-jetty3-1375039395742\collection1\, dataDir=.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty3\
[junit4] 2> 598315 T2283 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43caf0d8
[junit4] 2> 598316 T2283 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty3\
[junit4] 2> 598316 T2283 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty3\index/
[junit4] 2> 598316 T2283 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701\jetty3\index' doesn't exist. Creating new index...
[junit4] 2> 598316 T2283 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty3\index
[junit4] 2> 598321 T2283 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@16d9e5af lockFactory=org.apache.lucene.store.NativeFSLockFactory@61d029f4),segFN=segments_1,generation=1}
[junit4] 2> 598321 T2283 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 598327 T2283 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 598328 T2283 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 598328 T2283 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 598329 T2283 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 598329 T2283 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 598329 T2283 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 598329 T2283 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 598330 T2283 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 598330 T2283 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 598337 T2283 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 598339 T2283 oass.SolrIndexSearcher.<init> Opening Searcher@4ed41899 main
[junit4] 2> 598341 T2283 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 598341 T2283 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 598358 T2283 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 598358 T2283 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58108 collection:collection1 shard:shard1
[junit4] 2> 598359 T2283 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 598370 T2284 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4ed41899 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 598384 T2283 oasc.ZkController.register We are http://127.0.0.1:58108/collection1/ and leader is http://127.0.0.1:58089/collection1/
[junit4] 2> 598385 T2283 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58108
[junit4] 2> 598385 T2283 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 598385 T2283 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> 598386 T2283 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C5743 name=collection1 org.apache.solr.core.SolrCore@2fbee22 url=http://127.0.0.1:58108/collection1 node=127.0.0.1:58108_ C5743_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:58108_, base_url=http://127.0.0.1:58108}
[junit4] 2> 598387 T2285 C5743 P58108 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 598391 T2285 C5743 P58108 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 598391 T2285 C5743 P58108 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 598391 T2285 C5743 P58108 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 598393 T2207 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 598394 T2207 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 598394 T2207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 598505 T2285 C5743 P58108 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C5744 name=collection1 org.apache.solr.core.SolrCore@ea172fb url=http://127.0.0.1:58098/collection1 node=127.0.0.1:58098_ C5744_STATE=coll:collection1 core:collection1 props:{state=recovering, core=collection1, node_name=127.0.0.1:58098_, base_url=http://127.0.0.1:58098}
[junit4] 2> 598511 T2268 C5744 P58098 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:58089/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4] 2> 598513 T2268 C5744 P58098 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:58098 START replicas=[http://127.0.0.1:58089/collection1/] nUpdates=100
[junit4] 2> 598513 T2207 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 598514 T2240 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 598515 T2268 C5744 P58098 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4] 2> 598515 T2268 C5744 P58098 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4] 2> 598515 T2268 C5744 P58098 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4] 2> 598515 T2268 C5744 P58098 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4] 2> 598515 T2268 C5744 P58098 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 598515 T2268 C5744 P58098 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:58089/collection1/. core=collection1
[junit4] 2> 598515 T2268 C5744 P58098 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C5745 name=collection1 org.apache.solr.core.SolrCore@773258c2 url=http://127.0.0.1:58089/collection1 node=127.0.0.1:58089_ C5745_STATE=coll:collection1 core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:58089_, base_url=http://127.0.0.1:58089, leader=true}
[junit4] 2> 598523 T2241 C5745 P58089 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 598525 T2207 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4] 2> 598529 T2207 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4] 2> 598528 T2241 C5745 P58089 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@21a0cb2e lockFactory=org.apache.lucene.store.NativeFSLockFactory@5eb8c89b),segFN=segments_1,generation=1}
[junit4] 2> 598531 T2241 C5745 P58089 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 598531 T2241 C5745 P58089 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 598526 T2242 C5745 P58089 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4] 2> 598532 T2241 C5745 P58089 oass.SolrIndexSearcher.<init> Opening Searcher@400cb854 realtime
[junit4] 2> 598532 T2241 C5745 P58089 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 598532 T2241 C5745 P58089 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 9
[junit4] 2> 598534 T2268 C5744 P58098 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 598534 T2268 C5744 P58098 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 598545 T2243 C5745 P58089 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 598545 T2243 C5745 P58089 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 598546 T2268 C5744 P58098 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4] 2> 598546 T2268 C5744 P58098 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4] 2> 598546 T2268 C5744 P58098 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 598547 T2268 C5744 P58098 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 598551 T2207 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 598554 T2268 C5744 P58098 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4] 2> 599038 T2230 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 599040 T2230 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"recovering",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:58108_",
[junit4] 2> "base_url":"http://127.0.0.1:58108"}
[junit4] 2> 5990
[...truncated too long message...]
7 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 625036 T2207 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 625044 T2207 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 625045 T2207 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 625045 T2207 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty3\ [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty3\;done=false>>]
[junit4] 2> 625045 T2207 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty3\
[junit4] 2> 625045 T2207 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty3\index [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty3\index;done=false>>]
[junit4] 2> 625045 T2207 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.AliasIntegrationTest-1375039382701/jetty3\index
[junit4] 2> 625047 T2322 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90114580987379722-127.0.0.1:58108_-n_0000000003) am no longer a leader.
[junit4] 2> 625065 T2207 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701\zookeeper\server1\data\version-2\log.1 FAILED !!!!!
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701\zookeeper\server1\data\version-2 FAILED !!!!!
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701\zookeeper\server1\data FAILED !!!!!
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701\zookeeper\server1 FAILED !!!!!
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701\zookeeper FAILED !!!!!
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.AliasIntegrationTest-1375039382701 FAILED !!!!!
[junit4] 2> 625161 T2207 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 625164 T2207 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:58070 58070
[junit4] 2> 626482 T2282 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 627640 T2282 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 627641 T2282 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 1> -
[junit4] 1> rstate:down live:true
[junit4] 1> rstate:down live:true
[junit4] 1> -
[junit4] 1> rstate:down live:true
[junit4] 1> rstate:down live:true
[junit4] 1> -
[junit4] 1> rstate:active live:true
[junit4] 1> rstate:active live:true
[junit4] 1> no one is recoverying
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=AliasIntegrationTest -Dtests.method=testDistribSearch -Dtests.seed=A952590066AD228C -Dtests.slow=true -Dtests.locale=sr_ME -Dtests.timezone=America/Maceio -Dtests.file.encoding=UTF-8
[junit4] ERROR 45.2s | AliasIntegrationTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Collection not found: testalias
[junit4] > at __randomizedtesting.SeedInfo.seed([A952590066AD228C:28B4D71811F242B0]:0)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrServer.getCollectionList(CloudSolrServer.java:338)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:219)
[junit4] > at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
[junit4] > at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
[junit4] > at org.apache.solr.cloud.AliasIntegrationTest.doTest(AliasIntegrationTest.java:131)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 627652 T2207 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=388), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=388)), sim=DefaultSimilarity, locale=sr_ME, timezone=America/Maceio
[junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=2,threads=4,free=44761792,total=174551040
[junit4] 2> NOTE: All tests run in this JVM: [HdfsSyncSliceTest, HdfsLockFactoryTest, DocumentBuilderTest, WordBreakSolrSpellCheckerTest, TestSchemaNameResource, SolrCoreTest, IndexBasedSpellCheckerTest, TestSearchPerf, TestCoreContainer, AlternateDirectoryTest, TestDynamicFieldResource, LeaderElectionTest, DebugComponentTest, TestDocSet, TestDistributedSearch, PrimUtilsTest, TestSystemIdResolver, LukeRequestHandlerTest, HdfsUnloadDistributedZkTest, QueryParsingTest, ShowFileRequestHandlerTest, SearchHandlerTest, HdfsDirectoryTest, DefaultValueUpdateProcessorTest, TestLazyCores, ParsingFieldUpdateProcessorsTest, NoCacheHeaderTest, TestOmitPositions, RAMDirectoryFactoryTest, TestPropInjectDefaults, CurrencyFieldXmlFileTest, StatelessScriptUpdateProcessorFactoryTest, BadIndexSchemaTest, SliceStateTest, DistanceFunctionTest, TestRandomDVFaceting, ShardRoutingCustomTest, SolrPluginUtilsTest, TestSchemaVersionResource, AddSchemaFieldsUpdateProcessorFactoryTest, SolrIndexConfigTest, ScriptEngineTest, TestReload, TestDFRSimilarityFactory, MBeansHandlerTest, URLClassifyProcessorTest, TestBM25SimilarityFactory, SynonymTokenizerTest, TestManagedSchemaFieldResource, TestFaceting, SuggesterFSTTest, SignatureUpdateProcessorFactoryTest, RequestHandlersTest, SolrIndexSplitterTest, TestRecovery, DirectUpdateHandlerTest, TestClassNameShortening, HdfsRecoveryZkTest, TestShardHandlerFactory, BadComponentTest, CoreAdminHandlerTest, TestUtils, TestDistributedGrouping, TestJoin, SpellCheckCollatorTest, TestSolrQueryParserDefaultOperatorResource, SampleTest, SolrTestCaseJ4Test, OpenCloseCoreStressTest, TestRecoveryHdfs, TestFieldCollectionResource, TestCoreDiscovery, PreAnalyzedFieldTest, TestBadConfig, TestSolrDeletionPolicy2, OverseerCollectionProcessorTest, TestFieldTypeCollectionResource, TestAtomicUpdateErrorCases, TestExtendedDismaxParser, TimeZoneUtilsTest, DocumentAnalysisRequestHandlerTest, TestSolrIndexConfig, StressHdfsTest, StandardRequestHandlerTest, DateFieldTest, ShardRoutingTest, TestJmxMonitoredMap, TestCharFilters, CachingDirectoryFactoryTest, CopyFieldTest, TestDynamicFieldCollectionResource, TestDefaultSimilarityFactory, TestWordDelimiterFilterFactory, InfoHandlerTest, FieldAnalysisRequestHandlerTest, TestDefaultSearchFieldResource, TestPluginEnable, UniqFieldsUpdateProcessorFactoryTest, TestPseudoReturnFields, UpdateRequestProcessorFactoryTest, QueryElevationComponentTest, TestFieldResource, TestTrie, TestSolrXml, EchoParamsTest, TestDocumentBuilder, ResponseLogComponentTest, HighlighterConfigTest, TestStressRecovery, TestPhraseSuggestions, TestReloadAndDeleteDocs, MinimalSchemaTest, SOLR749Test, TestZkChroot, TestMaxScoreQueryParser, DirectSolrSpellCheckerTest, SuggesterWFSTTest, SuggesterTSTTest, TestSolrCoreProperties, TestRealTimeGet, BlockCacheTest, AliasIntegrationTest]
[junit4] Completed in 45.31s, 1 test, 1 error <<< FAILURES!
[...truncated 604 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:389: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:369: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:449: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1230: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:873: There were test failures: 318 suites, 1342 tests, 1 error, 42 ignored (11 assumptions)
Total time: 58 minutes 29 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-ea-b99 -XX:-UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.8.0-ea-b99) - Build
# 3086 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3086/
Java: 32bit/jdk1.8.0-ea-b99 -server -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestStressReplication
Error Message:
timed out waiting for collection1 startAt time to exceed: Mon Jul 29 00:48:19 SST 2013
Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Mon Jul 29 00:48:19 SST 2013
at __randomizedtesting.SeedInfo.seed([85D6A2B06C5D25C6:5E7DA27669754C75]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1507)
at org.apache.solr.handler.TestReplicationHandler.doTestStressReplication(TestReplicationHandler.java:811)
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:491)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 9479 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> 692376 T1883 oas.SolrTestCaseJ4.setUp ###Starting doTestStressReplication
[junit4] 2> 692392 T1883 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 692401 T1883 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60460
[junit4] 2> 692403 T1883 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 692403 T1883 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 692404 T1883 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master
[junit4] 2> 692404 T1883 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\'
[junit4] 2> 692449 T1883 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\solr.xml
[junit4] 2> 692449 T1883 oasc.ConfigSolr.fromFile C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\solr.xml does not exist, using default configuration
[junit4] 2> 692469 T1883 oasc.CoreContainer.<init> New CoreContainer 12007319
[junit4] 2> 692470 T1883 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\]
[junit4] 2> 692470 T1883 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 692470 T1883 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 692471 T1883 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 692471 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 692471 T1883 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 692471 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 692472 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 692473 T1883 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 692473 T1883 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 692473 T1883 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 692492 T1893 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1
[junit4] 2> 692492 T1893 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\'
[junit4] 2> 692519 T1893 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 692537 T1893 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 692537 T1893 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 692541 T1893 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 692547 T1893 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 692548 T1893 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 692548 T1893 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\
[junit4] 2> 692548 T1893 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 692549 T1893 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\
[junit4] 2> 692549 T1893 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\index/
[junit4] 2> 692549 T1893 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\index' doesn't exist. Creating new index...
[junit4] 2> 692549 T1893 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\index
[junit4] 2> 692551 T1893 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c71e05 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@15ca8e0),segFN=segments_1,generation=1}
[junit4] 2> 692551 T1893 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 692552 T1893 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 692553 T1893 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 692553 T1893 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 692553 T1893 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 692553 T1893 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 692554 T1893 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 692560 T1893 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 692563 T1893 oass.SolrIndexSearcher.<init> Opening Searcher@98544d main
[junit4] 2> 692563 T1893 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 692564 T1893 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 692564 T1893 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 692564 T1893 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 692564 T1894 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@98544d main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 692565 T1893 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 692568 T1883 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 692568 T1883 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 692571 T1883 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 692592 T1883 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 692598 T1883 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60463
[junit4] 2> 692599 T1883 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 692599 T1883 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 692601 T1883 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave
[junit4] 2> 692601 T1883 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\'
[junit4] 2> 692621 T1883 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\solr.xml
[junit4] 2> 692624 T1883 oasc.ConfigSolr.fromFile C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\solr.xml does not exist, using default configuration
[junit4] 2> 692636 T1883 oasc.CoreContainer.<init> New CoreContainer 8861019
[junit4] 2> 692637 T1883 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\]
[junit4] 2> 692639 T1883 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 692639 T1883 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 692639 T1883 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 692639 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 692639 T1883 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 692640 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 692640 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 692641 T1883 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 692641 T1883 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 692641 T1883 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 692658 T1905 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1
[junit4] 2> 692658 T1905 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\'
[junit4] 2> 692684 T1905 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 692696 T1905 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 692696 T1905 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 692701 T1905 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 692707 T1905 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 692707 T1905 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 692710 T1905 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\
[junit4] 2> 692710 T1905 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 692711 T1905 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\
[junit4] 2> 692711 T1905 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index/
[junit4] 2> 692711 T1905 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index' doesn't exist. Creating new index...
[junit4] 2> 692711 T1905 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index
[junit4] 2> 692712 T1905 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8aa02f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@fcb292),segFN=segments_1,generation=1}
[junit4] 2> 692712 T1905 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 692713 T1905 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 692714 T1905 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 692714 T1905 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 692714 T1905 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 692714 T1905 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 692714 T1905 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 692717 T1905 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 692719 T1905 oass.SolrIndexSearcher.<init> Opening Searcher@19dbc08 main
[junit4] 2> 692719 T1905 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 692719 T1905 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 692725 T1905 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 692725 T1905 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 692725 T1906 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@19dbc08 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 692727 T1883 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 692727 T1883 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 692727 T1883 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 692752 T1883 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=8861019
[junit4] 2> 692755 T1883 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@35263b
[junit4] 2> 692756 T1883 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 692756 T1883 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 692756 T1883 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 692756 T1883 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 692757 T1883 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 692759 T1883 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 692759 T1883 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\;done=false>>]
[junit4] 2> 692760 T1883 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\
[junit4] 2> 692760 T1883 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index;done=false>>]
[junit4] 2> 692760 T1883 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index
[junit4] 2> 692761 T1883 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 692815 T1883 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 692821 T1883 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60466
[junit4] 2> 692822 T1883 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 692823 T1883 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 692823 T1883 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave
[junit4] 2> 692823 T1883 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\'
[junit4] 2> 692843 T1883 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\solr.xml
[junit4] 2> 692843 T1883 oasc.ConfigSolr.fromFile C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\solr.xml does not exist, using default configuration
[junit4] 2> 692858 T1883 oasc.CoreContainer.<init> New CoreContainer 27997249
[junit4] 2> 692859 T1883 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\]
[junit4] 2> 692859 T1883 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 692860 T1883 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 692860 T1883 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 692860 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 692860 T1883 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 692861 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 692861 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 692861 T1883 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 692861 T1883 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 692862 T1883 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 692877 T1918 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1
[junit4] 2> 692877 T1918 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\'
[junit4] 2> 692903 T1918 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 692914 T1918 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 692914 T1918 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 692918 T1918 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 692925 T1918 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 692925 T1918 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 692926 T1918 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\
[junit4] 2> 692926 T1918 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 692926 T1918 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\
[junit4] 2> 692926 T1918 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index/
[junit4] 2> 692926 T1918 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index' doesn't exist. Creating new index...
[junit4] 2> 692927 T1918 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index
[junit4] 2> 692929 T1918 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f823 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@19b6bb8),segFN=segments_1,generation=1}
[junit4] 2> 692929 T1918 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 692930 T1918 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 692930 T1918 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 692930 T1918 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 692930 T1918 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 692931 T1918 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 692932 T1918 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 692933 T1918 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 692936 T1918 oass.SolrIndexSearcher.<init> Opening Searcher@4bbc22 main
[junit4] 2> 692936 T1918 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 692936 T1918 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 692937 T1918 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 692937 T1918 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 692937 T1919 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4bbc22 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 692938 T1883 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 692938 T1883 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 692938 T1883 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 692977 T1883 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=12007319
[junit4] 2> 692979 T1883 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@97fd36
[junit4] 2> 692979 T1883 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 692979 T1883 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 692979 T1883 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 692979 T1883 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 692980 T1883 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 692981 T1883 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 692981 T1883 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\;done=false>>]
[junit4] 2> 692981 T1883 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\
[junit4] 2> 692981 T1883 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\index;done=false>>]
[junit4] 2> 692982 T1883 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\index
[junit4] 2> 692982 T1883 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 693036 T1883 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 693042 T1883 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60469
[junit4] 2> 693044 T1883 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 693044 T1883 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 693045 T1883 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master
[junit4] 2> 693045 T1883 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\'
[junit4] 2> 693063 T1883 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\solr.xml
[junit4] 2> 693064 T1883 oasc.ConfigSolr.fromFile C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\solr.xml does not exist, using default configuration
[junit4] 2> 693077 T1883 oasc.CoreContainer.<init> New CoreContainer 28890762
[junit4] 2> 693077 T1883 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\]
[junit4] 2> 693078 T1883 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 693079 T1883 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 693079 T1883 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 693079 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 693079 T1883 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 693080 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 693080 T1883 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 693080 T1883 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 693081 T1883 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 693081 T1883 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 693091 T1930 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1
[junit4] 2> 693091 T1930 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\'
[junit4] 2> 693122 T1930 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 693132 T1930 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 693133 T1930 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 693138 T1930 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 693144 T1930 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 693145 T1930 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 693145 T1930 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\
[junit4] 2> 693145 T1930 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 693146 T1930 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\
[junit4] 2> 693146 T1930 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\index/
[junit4] 2> 693146 T1930 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\index' doesn't exist. Creating new index...
[junit4] 2> 693146 T1930 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499373\master\collection1\data\index
[junit4] 2> 693149 T1930 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1870646 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d5998),segFN=segments_1,generation=1}
[junit4] 2> 693149 T1930 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 693150 T1930 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 693150 T1930 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 693151 T1930 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 693151 T1930 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 693151 T1930 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 693151 T1930 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 693154 T1930 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 693155 T1930 oass.SolrIndexSearcher.<init> Opening Searcher@1492d5 main
[junit4] 2> 693155 T1930 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 693155 T1930 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 693155 T1930 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml
[junit4] 2> 693156 T1930 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1870646 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d5998),segFN=segments_1,generation=1}
[junit4] 2> 693156 T1930 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 693157 T1930 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 693157 T1930 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 693157 T1931 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1492d5 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 693159 T1883 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 693159 T1883 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 693159 T1883 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C917 name=collection1 org.apache.solr.core.SolrCore@1c62c5c
[junit4] 2> 693168 T1924 C917 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 693170 T1924 C917 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:*} 0 2
[junit4] 2> ASYNC NEW_CORE C918 name=collection1 org.apache.solr.core.SolrCore@7b4696
[junit4] 2> 693173 T1912 C918 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 693176 T1912 C918 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f823 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@19b6bb8),segFN=segments_1,generation=1}
[junit4] 2> 693176 T1912 C918 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 693177 T1912 C918 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:*} 0 4
[junit4] 2> 693182 T1913 C918 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 693182 T1913 C918 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f823 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@19b6bb8),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f823 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@19b6bb8),segFN=segments_2,generation=2}
[junit4] 2> 693182 T1913 C918 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 693183 T1913 C918 oass.SolrIndexSearcher.<init> Opening Searcher@1e7cd36 main
[junit4] 2> 693184 T1913 C918 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 693184 T1919 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e7cd36 main{StandardDirectoryReader(segments_2:2:nrt)}
[junit4] 2> 693184 T1913 C918 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 3
[junit4] 2> 693189 T1925 C917 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0]} 0 1
[junit4] 2> 693193 T1926 C917 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 693195 T1926 C917 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1870646 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d5998),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1870646 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d5998),segFN=segments_2,generation=2}
[junit4] 2> 693196 T1926 C917 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 693198 T1926 C917 oass.SolrIndexSearcher.<init> Opening Searcher@796358 main
[junit4] 2> 693199 T1926 C917 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 693199 T1931 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@796358 main{StandardDirectoryReader(segments_2:4:nrt _0(5.0):c1)}
[junit4] 2> 693199 T1926 C917 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 6
[junit4] 2> 693212 T1927 C917 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=9
[junit4] 2> 693217 T1914 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 693222 T1933 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 693222 T1933 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 693225 T1928 C917 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 693226 T1933 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4] 2> 693226 T1933 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
[junit4] 2> 693226 T1933 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 693249 T1929 C917 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=21
[junit4] 2> 693250 T1933 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 4
[junit4] 2> 693251 T1933 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index.20130729004820246
[junit4] 2> 693251 T1933 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6bee5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d7280) fullCopy=true
[junit4] 2> 693254 T1924 C917 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C919 name=collection1 org.apache.solr.core.SolrCore@1c62c5c
[junit4] 2> 693265 T1925 C919 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 693269 T1926 C919 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 693272 T1927 C919 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 693274 T1933 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 693276 T1933 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130729004820246
[junit4] 2> 693276 T1933 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f823 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@19b6bb8)
[junit4] 2> 693276 T1933 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 693277 T1933 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 693277 T1933 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 693277 T1933 oasc.SolrCore.getNewIndexDir New index directory detected: old=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index/ new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index.20130729004820246
[junit4] 2> 693278 T1933 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6bee5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d7280),segFN=segments_2,generation=2}
[junit4] 2> 693280 T1933 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 693280 T1933 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 693280 T1933 oass.SolrIndexSearcher.<init> Opening Searcher@1182aae main
[junit4] 2> 693281 T1919 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1182aae main{StandardDirectoryReader(segments_2:4:nrt _0(5.0):c1)}
[junit4] 2> ASYNC NEW_CORE C920 name=collection1 org.apache.solr.core.SolrCore@7b4696
[junit4] 2> 693281 T1915 C920 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:60469/solr/replication&command=fetchindex&wait=true} status=0 QTime=60
[junit4] 2> 693283 T1915 C920 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index;done=true>>]
[junit4] 2> 693283 T1915 C920 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index
[junit4] 2> 693287 T1917 C920 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=1
[junit4] 2> 693291 T1928 C919 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=2
[junit4] 2> 693293 T1929 C919 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> 693300 T1924 C919 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> 693303 T1912 C920 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=6
[junit4] 2> 693305 T1925 C919 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> 693309 T1913 C920 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> 693314 T1914 C920 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 1
[junit4] 2> 693318 T1915 C920 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 0
[junit4] 2> 693321 T1916 C920 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[3]} 0 0
[junit4] 2> 693325 T1917 C920 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 693329 T1917 C920 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6bee5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d7280),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6bee5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d7280),segFN=segments_3,generation=3}
[junit4] 2> 693329 T1917 C920 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 693331 T1917 C920 oass.SolrIndexSearcher.<init> Opening Searcher@109bd96 main
[junit4] 2> 693332 T1917 C920 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 693332 T1919 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@109bd96 main{StandardDirectoryReader(segments_3:6:nrt _0(5.0):c1 _1(5.0):c3)}
[junit4] 2> 693332 T1917 C920 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 7
[junit4] 2> 693338 T1926 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[4]} 0 1
[junit4] 2> 693342 T1927 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[5]} 0 0
[junit4] 2> 693346 T1928 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[6]} 0 0
[junit4] 2> 693349 T1929 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[7]} 0 0
[junit4] 2> 693353 T1924 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[8]} 0 0
[junit4] 2> 693357 T1925 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[9]} 0 0
[junit4] 2> 693360 T1926 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[10]} 0 0
[junit4] 2> 693364 T1927 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[11]} 0 0
[junit4] 2> 693368 T1928 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[12]} 0 0
[junit4] 2> 693373 T1929 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[13]} 0 0
[junit4] 2> 693376 T1924 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[14]} 0 0
[junit4] 2> 693380 T1925 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[15]} 0 0
[junit4] 2> 693384 T1926 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[16]} 0 0
[junit4] 2> 693387 T1927 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[17]} 0 0
[junit4] 2> 693391 T1928 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[18]} 0 0
[junit4] 2> 693396 T1929 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[19]} 0 1
[junit4] 2> 693398 T1924 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[20]} 0 0
[junit4] 2> 693402 T1925 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[21]} 0 0
[junit4] 2> 693406 T1926 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[22]} 0 0
[junit4] 2> 693409 T1927 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[23]} 0 0
[junit4] 2> 693413 T1928 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[24]} 0 0
[junit4] 2> 693418 T1929 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[25]} 0 0
[junit4] 2> 693422 T1924 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[26]} 0 0
[junit4] 2> 693425 T1925 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[27]} 0 0
[junit4] 2> 693429 T1926 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[28]} 0 0
[junit4] 2> 693433 T1927 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[29]} 0 0
[junit4] 2> 693436 T1928 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[30]} 0 0
[junit4] 2> 693440 T1929 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[31]} 0 0
[junit4] 2> 693444 T1924 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[32]} 0 0
[junit4] 2> 693447 T1926 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[33]} 0 0
[junit4] 2> 693451 T1927 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[34]} 0 0
[junit4] 2> 693455 T1928 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[35]} 0 0
[junit4] 2> 693458 T1929 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[36]} 0 0
[junit4] 2> 693462 T1925 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[37]} 0 0
[junit4] 2> 693466 T1924 C919 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[38]} 0 0
[junit4] 2> ASYNC NEW_CORE C921 name=collection1 org.apache.solr.core.SolrCore@1c62c5c
[junit4] 2> 693475 T1926 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[39]} 0 1
[junit4] 2> 693479 T1927 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[40]} 0 0
[junit4] 2> 693483 T1928 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[41]} 0 0
[junit4] 2> 693486 T1929 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[42]} 0 0
[junit4] 2> 693490 T1925 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[43]} 0 0
[junit4] 2> 693494 T1924 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[44]} 0 0
[junit4] 2> 693497 T1926 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[45]} 0 0
[junit4] 2> 693501 T1927 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[46]} 0 0
[junit4] 2> 693505 T1928 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[47]} 0 0
[junit4] 2> 693508 T1929 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[48]} 0 0
[junit4] 2> 693512 T1925 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[49]} 0 0
[junit4] 2> 693516 T1924 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[50]} 0 0
[junit4] 2> 693521 T1926 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[51]} 0 0
[junit4] 2> 693524 T1927 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[52]} 0 0
[junit4] 2> 693528 T1928 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[53]} 0 0
[junit4] 2> 693532 T1929 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[54]} 0 0
[junit4] 2> 693535 T1925 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[55]} 0 0
[junit4] 2> 693539 T1924 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[56]} 0 0
[junit4] 2> 693543 T1926 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[57]} 0 0
[junit4] 2> 693546 T1927 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[58]} 0 0
[junit4] 2> 693550 T1928 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[59]} 0 0
[junit4] 2> 693555 T1929 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[60]} 0 1
[junit4] 2> 693559 T1925 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[61]} 0 2
[junit4] 2> 693561 T1924 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[62]} 0 0
[junit4] 2> 693566 T1926 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[63]} 0 0
[junit4] 2> 693570 T1927 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[64]} 0 0
[junit4] 2> 693573 T1928 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[65]} 0 0
[junit4] 2> 693577 T1929 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[66]} 0 0
[junit4] 2> 693581 T1925 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[67]} 0 0
[junit4] 2> 693584 T1924 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[68]} 0 0
[junit4] 2> 693588 T1926 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[69]} 0 0
[junit4] 2> 693592 T1927 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[70]} 0 0
[junit4] 2> 693595 T1928 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[71]} 0 0
[junit4] 2> 693599 T1929 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[72]} 0 0
[junit4] 2> 693603 T1925 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[73]} 0 0
[junit4] 2> 693606 T1924 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[74]} 0 0
[junit4] 2> 693610 T1926 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[75]} 0 0
[junit4] 2> 693614 T1927 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[76]} 0 0
[junit4] 2> 693617 T1928 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[77]} 0 0
[junit4] 2> 693621 T1929 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[78]} 0 0
[junit4] 2> 693625 T1925 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[79]} 0 0
[junit4] 2> 693629 T1924 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[80]} 0 1
[junit4] 2> 693633 T1926 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[81]} 0 0
[junit4] 2> 693637 T1927 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[82]} 0 0
[junit4] 2> 693641 T1928 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[83]} 0 0
[junit4] 2> 693644 T1929 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[84]} 0 0
[junit4] 2> 693648 T1925 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[85]} 0 0
[junit4] 2> 693652 T1924 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[86]} 0 0
[junit4] 2> 693655 T1926 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[87]} 0 0
[junit4] 2> 693659 T1927 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[88]} 0 0
[junit4] 2> 693663 T1928 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[89]} 0 0
[junit4] 2> 693666 T1929 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[90]} 0 0
[junit4] 2> 693670 T1925 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[91]} 0 0
[junit4] 2> 693674 T1924 C921 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 693680 T1924 C921 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1870646 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d5998),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1870646 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d5998),segFN=segments_3,generation=3}
[junit4] 2> 693680 T1924 C921 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 693682 T1924 C921 oass.SolrIndexSearcher.<init> Opening Searcher@12b9116 main
[junit4] 2> 693682 T1924 C921 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 693683 T1931 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@12b9116 main{StandardDirectoryReader(segments_3:6:nrt _0(5.0):c1 _1(5.0):c88)}
[junit4] 2> 693683 T1924 C921 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 9
[junit4] 2> 693688 T1926 C921 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=89 status=0 QTime=1
[junit4] 2> 693692 T1912 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 693696 T1935 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 693696 T1935 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 693699 T1927 C921 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 693700 T1935 oash.SnapPuller.fetchLatestIndex Master's generation: 3
[junit4] 2> 693700 T1935 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
[junit4] 2> 693700 T1935 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 693705 T1928 C921 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=3&version=2} status=0 QTime=2
[junit4] 2> 693708 T1935 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 7
[junit4] 2> 693708 T1935 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index.20130729004820704
[junit4] 2> 693708 T1935 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aab65a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d1b2cd) fullCopy=true
[junit4] 2> 693711 T1929 C921 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 693716 T1925 C921 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 693720 T1924 C921 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C922 name=collection1 org.apache.solr.core.SolrCore@1c62c5c
[junit4] 2> 693730 T1926 C922 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 693735 T1927 C922 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 693738 T1928 C922 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_3&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 693742 T1929 C922 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 693743 T1935 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 693746 T1935 oash.SnapPuller.downloadConfFiles Starting download of configuration files from master: [{name=schema.xml, checksum=1505963717, size=1634}]
[junit4] 2> 693763 T1925 C922 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filecontent&checksum=true&wt=filestream&cf=schema.xml&qt=/replication&generation=3} status=0 QTime=5
[junit4] 2> 693787 T1935 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130729004820704
[junit4] 2> 693787 T1935 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6bee5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d7280)
[junit4] 2> 693787 T1935 oash.SnapPuller.fetchLatestIndex Configuration files are modified, core will be reloaded
[junit4] 2> 693795 T1935 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6bee5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d7280)
[junit4] 2> 693795 T1935 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 693796 T1937 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1
[junit4] 2> 693796 T1937 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\'
[junit4] 2> 693796 T1935 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 693796 T1935 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 693797 T1935 oasc.SolrCore.getNewIndexDir New index directory detected: old=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index.20130729004820246 new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index.20130729004820704
[junit4] 2> 693852 T1937 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 693863 T1937 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 693863 T1937 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 693868 T1937 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 693879 T1937 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 693926 T1935 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1aab65a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d1b2cd),segFN=segments_3,generation=3}
[junit4] 2> 693927 T1935 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 693927 T1935 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 693927 T1937 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\
[junit4] 2> 693927 T1937 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 693927 T1937 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index.20130729004820704
[junit4] 2> 693928 T1937 oasc.SolrCore.initIndex ERROR [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index.20130729004820704' is locked. Throwing exception
[junit4] 2> 693929 T1937 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@2bc0e0
[junit4] 2> 693929 T1937 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 693929 T1937 oasc.CoreContainer.recordAndThrow ERROR Unable to reload core: collection1 org.apache.solr.common.SolrException: Index locked for write for core collection1
[junit4] 2> at org.apache.solr.core.SolrCore.<init>(SolrCore.java:831)
[junit4] 2> at org.apache.solr.core.SolrCore.reload(SolrCore.java:413)
[junit4] 2> at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:675)
[junit4] 2> at org.apache.solr.handler.SnapPuller$2.run(SnapPuller.java:688)
[junit4] 2> Caused by: org.apache.lucene.store.LockObtainFailedException: Index locked for write for core collection1
[junit4] 2> at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:490)
[junit4] 2> at org.apache.solr.core.SolrCore.<init>(SolrCore.java:754)
[junit4] 2> ... 3 more
[junit4] 2>
[junit4] 2> 693930 T1937 oash.SnapPuller$2.run ERROR Could not reload core org.apache.solr.common.SolrException: Unable to reload core: collection1
[junit4] 2> at org.apache.solr.core.CoreContainer.recordAndThrow(CoreContainer.java:930)
[junit4] 2> at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:685)
[junit4] 2> at org.apache.solr.handler.SnapPuller$2.run(SnapPuller.java:688)
[junit4] 2> Caused by: org.apache.solr.common.SolrException: Index locked for write for core collection1
[junit4] 2> at org.apache.solr.core.SolrCore.<init>(SolrCore.java:831)
[junit4] 2> at org.apache.solr.core.SolrCore.reload(SolrCore.java:413)
[junit4] 2> at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:675)
[junit4] 2> ... 1 more
[junit4] 2> Caused by: org.apache.lucene.store.LockObtainFailedException: Index locked for write for core collection1
[junit4] 2> at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:490)
[junit4] 2> at org.apache.solr.core.SolrCore.<init>(SolrCore.java:754)
[junit4] 2> ... 3 more
[junit4] 2>
[junit4] 2> 693930 T1935 oass.SolrIndexSearcher.<init> Opening Searcher@5735c2 main
[junit4] 2> 693932 T1919 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5735c2 main{StandardDirectoryReader(segments_3:6:nrt _0(5.0):c1 _1(5.0):c88)}
[junit4] 2> ASYNC NEW_CORE C923 name=collection1 org.apache.solr.core.SolrCore@7b4696
[junit4] 2> 693932 T1914 C923 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:60469/solr/replication&command=fetchindex&wait=true} status=0 QTime=238
[junit4] 2> 693933 T1914 C923 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index.20130729004820246 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index.20130729004820246;done=true>>]
[junit4] 2> 693933 T1914 C923 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098499575\slave\collection1\data\index.20130729004820246
[junit4] 2> 693935 T1915 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 694191 T1916 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 694444 T1913 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 694699 T1912 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 694954 T1915 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 695209 T1917 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 695463 T1913 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 695719 T1914 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 695972 T1915 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 696227 T1916 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 696481 T1913 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 696735 T1912 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 696990 T1915 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 697246 T1917 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 697500 T1913 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 697754 T1914 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 698010 T1915 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 698265 T1916 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 698519 T1913 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 698773 T1912 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 699029 T1915 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 699285 T1917 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 699539 T1913 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 699794 T1914 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 700049 T1915 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 700305 T1916 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 700561 T1913 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 700827 T1912 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 701107 T1915 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 701386 T1916 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 701668 T1913 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 701948 T1914 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 702229 T1915 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 702507 T1917 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 702787 T1913 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 703067 T1912 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 703347 T1915 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 703627 T1916 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 703908 T1913 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 704188 T1914 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 704467 T1915 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 704748 T1917 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 705032 T1913 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 705312 T1912 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&core=collection1&wt=javabin&version=2} stat
[...truncated too long message...]
=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1
[junit4] 2> 769455 T2524 C1034 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=3
[junit4] 2> 769460 T2521 C1034 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1
[junit4] 2> 769460 T2547 C1035 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=2
[junit4] 2> 769461 T1883 oas.SolrTestCaseJ4.tearDown ###Ending doTestSnapPullWithMasterUrl
[junit4] 2> 769469 T1883 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=11142732
[junit4] 2> 769470 T1883 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@ef2645
[junit4] 2> 769470 T1883 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=496,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4] 2> 769471 T1883 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 769471 T1883 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 769471 T1883 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 769472 T1883 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 769472 T1883 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 769473 T1883 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574231\master\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574231\master\collection1\data\;done=false>>]
[junit4] 2> 769473 T1883 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574231\master\collection1\data\
[junit4] 2> 769474 T1883 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574231\master\collection1\data\index.20130729004936282 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574231\master\collection1\data\index.20130729004936282;done=false>>]
[junit4] 2> 769474 T1883 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574231\master\collection1\data\index.20130729004936282
[junit4] 2> 769474 T1883 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 769534 T1883 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=841407
[junit4] 2> 769534 T1883 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1e74605
[junit4] 2> 769534 T1883 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=3,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4] 2> 769534 T1883 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 769534 T1883 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 769535 T1883 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 769536 T1883 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 769536 T1883 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 769537 T1883 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574358\slave\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574358\slave\collection1\data\;done=false>>]
[junit4] 2> 769537 T1883 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574358\slave\collection1\data\
[junit4] 2> 769537 T1883 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574358\slave\collection1\data\index.20130729004936086 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574358\slave\collection1\data\index.20130729004936086;done=false>>]
[junit4] 2> 769538 T1883 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375098574358\slave\collection1\data\index.20130729004936086
[junit4] 2> 769538 T1883 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 769615 T1883 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene42: {newname=PostingsFormat(name=Direct), id=PostingsFormat(name=Direct), name=PostingsFormat(name=Direct)}, docValues:{}, sim=DefaultSimilarity, locale=es_GT, timezone=Pacific/Midway
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.8.0-ea (32-bit)/cpus=2,threads=1,free=63518744,total=216735744
[junit4] 2> NOTE: All tests run in this JVM: [SoftAutoCommitTest, PathHierarchyTokenizerFactoryTest, OpenExchangeRatesOrgProviderTest, WordBreakSolrSpellCheckerTest, SynonymTokenizerTest, TestWriterPerf, PeerSyncTest, SimplePostToolTest, TestPhraseSuggestions, TestReloadAndDeleteDocs, TestSolrXml, SolrIndexSplitterTest, TestReload, SliceStateUpdateTest, TestElisionMultitermQuery, TestMaxScoreQueryParser, ExternalFileFieldSortTest, TestJmxIntegration, ShardRoutingCustomTest, TestQueryTypes, CurrencyFieldXmlFileTest, FieldMutatingUpdateProcessorTest, TestTrie, UniqFieldsUpdateProcessorFactoryTest, DefaultValueUpdateProcessorTest, TestBinaryField, LeaderElectionTest, TestDynamicFieldCollectionResource, SearchHandlerTest, HardAutoCommitTest, QueryElevationComponentTest, AliasIntegrationTest, TestLuceneMatchVersion, DocumentAnalysisRequestHandlerTest, TestXIncludeConfig, TestDefaultSearchFieldResource, UUIDFieldTest, TestPHPSerializedResponseWriter, TestDistributedSearch, TestBM25SimilarityFactory, TestCoreContainer, UnloadDistributedZkTest, DocValuesTest, TestLFUCache, ZkControllerTest, LegacyHTMLStripCharFilterTest, TestRangeQuery, ResponseLogComponentTest, TestSolrCoreProperties, OverseerTest, ClusterStateUpdateTest, TestLRUCache, ZkCLITest, SolrCoreCheckLockOnStartupTest, TestBinaryResponseWriter, TestRecoveryHdfs, DistributedQueryElevationComponentTest, SimpleFacetsTest, AnalysisAfterCoreReloadTest, DebugComponentTest, PreAnalyzedFieldTest, MinimalSchemaTest, TestDynamicFieldResource, StandardRequestHandlerTest, DirectSolrSpellCheckerTest, BasicDistributedZkTest, TestReplicationHandler]
[junit4] Completed in 77.27s, 14 tests, 1 failure <<< FAILURES!
[...truncated 765 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:389: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:369: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:449: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1230: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:873: There were test failures: 318 suites, 1342 tests, 1 failure, 42 ignored (11 assumptions)
Total time: 63 minutes 13 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-ea-b99 -server -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.8.0-ea-b99) - Build
# 3085 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3085/
Java: 32bit/jdk1.8.0-ea-b99 -client -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.SliceStateUpdateTest.testSliceStateUpdate
Error Message:
expected:<[in]active> but was:<[]active>
Stack Trace:
org.junit.ComparisonFailure: expected:<[in]active> but was:<[]active>
at __randomizedtesting.SeedInfo.seed([B9443DCAA7760328:6926B086F9A3D9AC]:0)
at org.junit.Assert.assertEquals(Assert.java:125)
at org.junit.Assert.assertEquals(Assert.java:147)
at org.apache.solr.cloud.SliceStateUpdateTest.testSliceStateUpdate(SliceStateUpdateTest.java:183)
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:491)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 9773 lines...]
[junit4] Suite: org.apache.solr.cloud.SliceStateUpdateTest
[junit4] 2> 1560386 T5620 oas.SolrTestCaseJ4.setUp ###Starting testSliceStateUpdate
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522
[junit4] 2> 1560388 T5620 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1560389 T5621 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1560455 T5620 oasc.ZkTestServer.run start zk server on port:53275
[junit4] 2> 1560457 T5620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1560466 T5627 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1809a9a name:ZooKeeperConnection Watcher:127.0.0.1:53275 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1560466 T5620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1560466 T5620 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1560471 T5622 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1402880b9c80000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2>
[junit4] 2> 1560472 T5620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1560474 T5629 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1476d5a name:ZooKeeperConnection Watcher:127.0.0.1:53275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1560475 T5620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1560475 T5620 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1560479 T5620 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1560483 T5620 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1560485 T5620 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1560489 T5620 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1560489 T5620 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1560498 T5620 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1560499 T5620 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1560503 T5620 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1560504 T5620 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1560508 T5620 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1560508 T5620 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1560511 T5620 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1560512 T5620 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1560515 T5620 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1560515 T5620 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1560519 T5620 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1560520 T5620 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1560523 T5620 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1560524 T5620 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1560529 T5620 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1560530 T5620 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1560537 T5622 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1402880b9c80001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2>
[junit4] 2> 1560537 T5620 oasc.SliceStateUpdateTest.setUp ####SETUP_START testSliceStateUpdate
[junit4] 2> 1560539 T5620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1560542 T5631 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@178f1ea name:ZooKeeperConnection Watcher:127.0.0.1:53275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1560543 T5620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1560543 T5620 oascc.SolrZkClient.makePath makePath: /collections/testcore
[junit4] 2> 1560546 T5620 oascc.SolrZkClient.makePath makePath: /collections/testcore/shards
[junit4] 2> 1560560 T5620 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1560561 T5620 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr
[junit4] 2> 1560561 T5620 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\'
[junit4] 2> 1560592 T5620 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\solr.xml
[junit4] 2> 1560610 T5620 oasc.CoreContainer.<init> New CoreContainer 20219446
[junit4] 2> 1560611 T5620 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1560611 T5620 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr
[junit4] 2> 1560612 T5620 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\'
[junit4] 2> 1560626 T5620 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\solr.xml
[junit4] 2> 1560633 T5620 oasc.CoreContainer.<init> New CoreContainer 25725485
[junit4] 2> 1560634 T5620 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\]
[junit4] 2> 1560634 T5620 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1560634 T5620 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1560634 T5620 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1560634 T5620 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1560635 T5620 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1560635 T5620 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1560636 T5620 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1560636 T5620 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1560636 T5620 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1560637 T5620 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1560647 T5620 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53275/solr
[junit4] 2> 1560647 T5620 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1560649 T5620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1560653 T5633 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cba859 name:ZooKeeperConnection Watcher:127.0.0.1:53275 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1560653 T5620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1560664 T5620 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1560664 T5622 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1402880b9c80003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2>
[junit4] 2> 1560669 T5620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1560685 T5635 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67db43 name:ZooKeeperConnection Watcher:127.0.0.1:53275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1560685 T5620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1560700 T5620 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1560715 T5620 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1560719 T5620 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1560722 T5620 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:8983_solr
[junit4] 2> 1560724 T5620 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:8983_solr
[junit4] 2> 1560727 T5620 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1560734 T5620 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1560737 T5620 oasc.Overseer.start Overseer (id=90116525885227012-127.0.0.1:8983_solr-n_0000000000) starting
[junit4] 2> 1560743 T5620 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1560748 T5637 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1560748 T5620 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1560750 T5620 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1560753 T5620 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1560756 T5636 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1560758 T5638 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1560758 T5638 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1560760 T5638 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1561850 T5636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1561852 T5636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":null,
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:8983_solr",
[junit4] 2> "base_url":"http://127.0.0.1:8983/solr"}
[junit4] 2> 1561852 T5636 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1561889 T5635 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> 1562211 T5638 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1562211 T5638 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1
[junit4] 2> 1562211 T5638 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1562214 T5638 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1562214 T5638 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1562216 T5638 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\'
[junit4] 2> 1562222 T5638 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 1562223 T5638 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 1562255 T5638 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1562279 T5638 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1562282 T5638 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1562287 T5638 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1562401 T5638 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1562407 T5638 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1562408 T5638 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1562420 T5638 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1562423 T5638 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1562426 T5638 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1562427 T5638 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1562427 T5638 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1562427 T5638 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1562429 T5638 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1562429 T5638 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1562429 T5638 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1562429 T5638 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\
[junit4] 2> 1562430 T5638 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1de2857
[junit4] 2> 1562430 T5638 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\
[junit4] 2> 1562430 T5638 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index/
[junit4] 2> 1562430 T5638 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index' doesn't exist. Creating new index...
[junit4] 2> 1562430 T5638 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index
[junit4] 2> 1562433 T5638 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@f7d670 lockFactory=org.apache.lucene.store.NativeFSLockFactory@11aed1f)),segFN=segments_1,generation=1}
[junit4] 2> 1562433 T5638 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1562435 T5638 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 1562437 T5638 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1562437 T5638 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 1562437 T5638 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1562437 T5638 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 1562438 T5638 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1562438 T5638 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1562439 T5638 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1562439 T5638 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1562439 T5638 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1562439 T5638 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 1562440 T5638 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 1562441 T5638 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1562441 T5638 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 1562441 T5638 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 1562442 T5638 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 1562442 T5638 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1562442 T5638 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1562442 T5638 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1562443 T5638 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1562443 T5638 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1562444 T5638 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1562444 T5638 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1562444 T5638 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1562444 T5638 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1562445 T5638 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 1562446 T5638 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 1562452 T5638 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1562452 T5638 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 1562454 T5638 oasc.SolrCore.initDeprecatedSupport WARN adding ShowFileRequestHandler with hidden files: [OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4] 2> 1562454 T5638 oass.SolrIndexSearcher.<init> Opening Searcher@100c78a main
[junit4] 2> 1562456 T5638 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1562456 T5638 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1562456 T5638 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 1562469 T5638 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 1562517 T5639 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@100c78a main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1562527 T5638 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1562527 T5638 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:8983/solr collection:collection1 shard:shard1
[junit4] 2> 1562528 T5638 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1562536 T5638 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1562547 T5638 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1562551 T5638 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1562551 T5638 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1562551 T5638 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:8983/solr/collection1/ shard1
[junit4] 2> 1562551 T5638 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1562997 T5636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1563083 T5635 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> 1563150 T5638 oasc.ZkController.register We are http://127.0.0.1:8983/solr/collection1/ and leader is http://127.0.0.1:8983/solr/collection1/
[junit4] 2> 1563150 T5638 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:8983/solr
[junit4] 2> 1563151 T5638 oasc.ZkController.checkRecovery WARN Skipping recovery according to sys prop solrcloud.skip.autorecovery
[junit4] 2> 1563151 T5638 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1563151 T5638 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1563154 T5638 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1563156 T5620 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\]
[junit4] 2> 1563158 T5620 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1563158 T5620 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1563158 T5620 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1563159 T5620 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1563159 T5620 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1563160 T5620 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1563160 T5620 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1563160 T5620 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1563160 T5620 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1563161 T5620 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1563170 T5620 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53275/solr
[junit4] 2> 1563170 T5620 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1563172 T5620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1563175 T5642 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18fa561 name:ZooKeeperConnection Watcher:127.0.0.1:53275 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1563175 T5620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1563177 T5620 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1563177 T5622 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1402880b9c80005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2>
[junit4] 2> 1563182 T5620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1563185 T5644 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c03d9 name:ZooKeeperConnection Watcher:127.0.0.1:53275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1563185 T5620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1563189 T5620 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1563917 T5620 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:8983_solr
[junit4] 2> 1563922 T5635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1563923 T5620 oasc.ZkController.createEphemeralLiveNode Found a previous node that still exists while trying to register a new live node /live_nodes/127.0.0.1:8983_solr - removing existing node to create another.
[junit4] 2> 1563923 T5620 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:8983_solr
[junit4] 2> 1563923 T5644 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1563925 T5635 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1563926 T5635 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1563927 T5644 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1563927 T5635 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1563932 T5645 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1563932 T5645 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1563934 T5645 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1563934 T5645 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1563934 T5645 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1
[junit4] 2> 1563935 T5645 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1563936 T5645 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1563936 T5645 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1563937 T5645 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\'
[junit4] 2> 1563939 T5645 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 1563939 T5645 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 1563980 T5645 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1563999 T5645 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1564001 T5645 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1564008 T5645 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1564146 T5645 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1564152 T5645 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1564153 T5645 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1564167 T5645 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1564170 T5645 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1564172 T5645 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1564174 T5645 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1564174 T5645 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1564174 T5645 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1564175 T5645 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1564175 T5645 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1564175 T5645 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1564176 T5645 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\
[junit4] 2> 1564176 T5645 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1de2857
[junit4] 2> 1564177 T5645 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\
[junit4] 2> 1564177 T5645 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index/
[junit4] 2> 1564177 T5645 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index' doesn't exist. Creating new index...
[junit4] 2> 1564177 T5645 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index
[junit4] 2> 1564180 T5645 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@165053e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f0b207)),segFN=segments_1,generation=1}
[junit4] 2> 1564180 T5645 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1564181 T5645 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 1564184 T5645 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1564184 T5645 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 1564184 T5645 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1564184 T5645 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 1564185 T5645 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1564185 T5645 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1564185 T5645 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1564186 T5645 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1564187 T5645 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1564187 T5645 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 1564188 T5645 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 1564189 T5645 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1564189 T5645 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 1564189 T5645 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 1564189 T5645 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 1564190 T5645 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1564190 T5645 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1564191 T5645 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1564192 T5645 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1564192 T5645 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1564193 T5645 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1564194 T5645 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1564194 T5645 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1564195 T5645 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 1564196 T5645 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 1564196 T5645 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 1564202 T5645 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1564203 T5645 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 1564204 T5636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1564206 T5645 oasc.SolrCore.initDeprecatedSupport WARN adding ShowFileRequestHandler with hidden files: [OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4] 2> 1564206 T5636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":null,
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:8983_solr",
[junit4] 2> "base_url":"http://127.0.0.1:8983/solr"}
[junit4] 2> 1564207 T5645 oass.SolrIndexSearcher.<init> Opening Searcher@d0701b main
[junit4] 2> 1564209 T5645 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1564209 T5645 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1564210 T5645 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 1564214 T5645 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 1564231 T5646 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d0701b main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1564238 T5645 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1564238 T5645 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:8983/solr collection:collection1 shard:shard1
[junit4] 2> 1564239 T5645 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1564267 T5636 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 1564267 T5636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":null,
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:8983_solr",
[junit4] 2> "base_url":"http://127.0.0.1:8983/solr"}
[junit4] 2> 1564267 T5636 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1564282 T5645 oasc.ZkController.register We are http://127.0.0.1:8983/solr/collection1/ and leader is http://127.0.0.1:8983/solr/collection1/
[junit4] 2> 1564282 T5645 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:8983/solr
[junit4] 2> 1564282 T5645 oasc.ZkController.checkRecovery WARN Skipping recovery according to sys prop solrcloud.skip.autorecovery
[junit4] 2> 1564282 T5645 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1564282 T5645 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1564288 T5645 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1564289 T5636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":null,
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:8983_solr",
[junit4] 2> "base_url":"http://127.0.0.1:8983/solr"}
[junit4] 2> 1564290 T5620 oasc.SliceStateUpdateTest.setUp ####SETUP_END testSliceStateUpdate
[junit4] 2> 1564291 T5620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1564294 T5649 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ae1ab3 name:ZooKeeperConnection Watcher:127.0.0.1:53275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1564295 T5620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1564296 T5635 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> 1564297 T5644 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> 1597095 T5620 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=20219446
[junit4] 2> 1597190 T5636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1597193 T5636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:8983_solr",
[junit4] 2> "base_url":"http://127.0.0.1:8983/solr"}
[junit4] 2> 1597193 T5636 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1597212 T5635 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> 1597212 T5644 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> 1599230 T5620 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1599230 T5620 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1599236 T5620 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1b395c5
[junit4] 2> 1599255 T5620 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 1599255 T5620 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1599255 T5620 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1599256 T5620 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1599258 T5620 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 1599259 T5620 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1599259 T5620 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\;done=false>>]
[junit4] 2> 1599259 T5620 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\
[junit4] 2> 1599259 T5620 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index;done=false>>]
[junit4] 2> 1599259 T5620 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index
[junit4] 2> 1599262 T5636 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90116525885227012-127.0.0.1:8983_solr-n_0000000000) am no longer a leader.
[junit4] 2> 1599265 T5620 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=25725485
[junit4] 2> 1599268 T5644 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1599272 T5644 oasc.Overseer.start Overseer (id=90116525885227014-127.0.0.1:8983_solr-n_0000000001) starting
[junit4] 2> 1599283 T5651 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1599285 T5650 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1599287 T5644 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1599292 T5644 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4] 2> 1599292 T5650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1599292 T5644 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4] 2> 1599292 T5644 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1599292 T5644 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:8983/solr/collection1/ shard1
[junit4] 2> 1599293 T5644 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1599294 T5650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":null,
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:8983_solr",
[junit4] 2> "base_url":"http://127.0.0.1:8983/solr"}
[junit4] 2> 1599322 T5644 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> 1600327 T5620 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1600327 T5620 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1600333 T5620 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1b3d20a
[junit4] 2> 1600377 T5620 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 1600378 T5620 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1600378 T5620 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1600379 T5620 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1600380 T5620 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 1600380 T5620 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1600380 T5620 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\;done=false>>]
[junit4] 2> 1600380 T5620 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\
[junit4] 2> 1600381 T5620 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index;done=false>>]
[junit4] 2> 1600381 T5620 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-SliceStateUpdateTest-1375069059522\data2\index
[junit4] 2> 1600383 T5650 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90116525885227014-127.0.0.1:8983_solr-n_0000000001) am no longer a leader.
[junit4] 2> 1600386 T5644 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1600386 T5622 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1402880b9c80006, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2>
[junit4] 2> 1600387 T5644 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1600388 T5644 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1600388 T5620 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53275 53275
[junit4] 2> 1602784 T5620 oas.SolrTestCaseJ4.tearDown ###Ending testSliceStateUpdate
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SliceStateUpdateTest -Dtests.method=testSliceStateUpdate -Dtests.seed=B9443DCAA7760328 -Dtests.slow=true -Dtests.locale=sk -Dtests.timezone=Universal -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 42.4s | SliceStateUpdateTest.testSliceStateUpdate <<<
[junit4] > Throwable #1: org.junit.ComparisonFailure: expected:<[in]active> but was:<[]active>
[junit4] > at __randomizedtesting.SeedInfo.seed([B9443DCAA7760328:6926B086F9A3D9AC]:0)
[junit4] > at org.apache.solr.cloud.SliceStateUpdateTest.testSliceStateUpdate(SliceStateUpdateTest.java:183)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 1602817 T5620 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=DefaultSimilarity, locale=sk, timezone=Universal
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.8.0-ea (32-bit)/cpus=2,threads=1,free=76716024,total=192311296
[junit4] 2> NOTE: All tests run in this JVM: [TestSolrQueryParserResource, TermVectorComponentTest, MBeansHandlerTest, RecoveryZkTest, TestCodecSupport, TestExtendedDismaxParser, MoreLikeThisHandlerTest, LegacyHTMLStripCharFilterTest, TestUtils, JSONWriterTest, TestIndexingPerformance, TestRandomDVFaceting, HdfsBasicDistributedZk2Test, SystemInfoHandlerTest, FieldAnalysisRequestHandlerTest, TestFieldCollectionResource, XsltUpdateRequestHandlerTest, SearchHandlerTest, HdfsChaosMonkeySafeLeaderTest, TestAddFieldRealTimeGet, SortByFunctionTest, TestStressRecovery, PreAnalyzedFieldTest, TestPropInject, DocValuesTest, TestSolrCoreProperties, RegexBoostProcessorTest, UniqFieldsUpdateProcessorFactoryTest, CoreAdminCreateDiscoverTest, SynonymTokenizerTest, DistanceFunctionTest, SolrPluginUtilsTest, TestZkChroot, StandardRequestHandlerTest, TestGroupingSearch, SuggesterWFSTTest, BasicFunctionalityTest, TestJmxIntegration, DocValuesMultiTest, DirectSolrSpellCheckerTest, PeerSyncTest, NotRequiredUniqueKeyTest, TestCSVLoader, TestCopyFieldCollectionResource, TestLFUCache, TestSuggestSpellingConverter, PathHierarchyTokenizerFactoryTest, SpellCheckComponentTest, TestMaxScoreQueryParser, TestShardHandlerFactory, TestFastWriter, IndexReaderFactoryTest, TestConfig, TestManagedSchema, TestRandomFaceting, SuggesterTest, StressHdfsTest, TestCoreContainer, SolrCoreCheckLockOnStartupTest, ResourceLoaderTest, PrimitiveFieldTypeTest, TestFieldResource, SOLR749Test, WordBreakSolrSpellCheckerTest, DirectUpdateHandlerOptimizeTest, SpellCheckCollatorTest, TestSerializedLuceneMatchVersion, TestQueryTypes, TestPhraseSuggestions, CollectionsAPIDistributedZkTest, SliceStateTest, DateFieldTest, TestSystemIdResolver, SampleTest, UpdateRequestProcessorFactoryTest, TestReloadAndDeleteDocs, TestPluginEnable, TestRecoveryHdfs, ResponseLogComponentTest, DeleteShardTest, PreAnalyzedUpdateProcessorTest, TestSchemaResource, TestUpdate, BasicZkTest, TestRealTimeGet, IndexBasedSpellCheckerTest, TestReload, SignatureUpdateProcessorFactoryTest, FastVectorHighlighterTest, TestDocSet, RequestHandlersTest, TestCloudManagedSchemaAddField, BadIndexSchemaTest, TestSweetSpotSimilarityFactory, SolrCmdDistributorTest, HighlighterConfigTest, HardAutoCommitTest, RAMDirectoryFactoryTest, AssignTest, TestSort, SpatialFilterTest, QueryElevationComponentTest, TestAtomicUpdateErrorCases, SolrCoreTest, TestSolrDeletionPolicy2, TestSolrJ, TestRemoteStreaming, TestOmitPositions, ClusterStateTest, TestFastLRUCache, TestSolrQueryParser, DirectSolrConnectionTest, TimeZoneUtilsTest, QueryResultKeyTest, TestDefaultSimilarityFactory, TestWordDelimiterFilterFactory, TestSolrDeletionPolicy1, CoreContainerCoreInitFailuresTest, TestValueSourceCache, HdfsSyncSliceTest, BasicDistributedZk2Test, TestSolrXmlPersistence, TestSolrXMLSerializer, AliasIntegrationTest, ChaosMonkeyNothingIsSafeTest, TestIndexSearcher, HdfsUnloadDistributedZkTest, TestStressVersions, MinimalSchemaTest, NoCacheHeaderTest, HdfsDirectoryTest, TestFieldTypeResource, TestBinaryResponseWriter, FileUtilsTest, TestCollationField, DefaultValueUpdateProcessorTest, XmlUpdateRequestHandlerTest, NumericFieldsTest, TestLMJelinekMercerSimilarityFactory, BadComponentTest, URLClassifyProcessorTest, UpdateParamsTest, TestFunctionQuery, TestElisionMultitermQuery, TestCoreDiscovery, OpenCloseCoreStressTest, ParsingFieldUpdateProcessorsTest, DistributedSpellCheckComponentTest, TestRTGBase, SimpleFacetsTest, BadCopyFieldTest, OverseerTest, TermsComponentTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, SyncSliceTest, LeaderElectionIntegrationTest, ShardRoutingTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler, ClusterStateUpdateTest, LeaderElectionTest, ZkSolrClientTest, ZkCLITest, ShardRoutingCustomTest, SliceStateUpdateTest]
[junit4] Completed in 42.51s, 1 test, 1 failure <<< FAILURES!
[...truncated 454 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:389: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:369: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:449: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1230: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:873: There were test failures: 318 suites, 1342 tests, 1 failure, 42 ignored (11 assumptions)
Total time: 55 minutes 41 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-ea-b99 -client -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure