Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-5.2/2/
1 tests failed. FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test Error Message: Captured an uncaught exception in thread: Thread[id=5762, name=collection4, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] Stack Trace: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=5762, name=collection4, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:46708: Could not find collection : awholynewstresscollection_collection4_0 at __randomizedtesting.SeedInfo.seed([2418605820CD177C]:0) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328) at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799) at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:884) Build Log: [...truncated 20915 lines...] [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/init-core-data-001 [junit4] 2> 994471 T5422 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false) [junit4] 2> 994472 T5422 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: / [junit4] 2> 994476 T5422 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 2> 994476 T5423 oasc.ZkTestServer$2$1.setClientPort client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 994476 T5423 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 994576 T5422 oasc.ZkTestServer.run start zk server on port:42495 [junit4] 2> 994577 T5422 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 994577 T5422 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 994580 T5430 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1487f335 name:ZooKeeperConnection Watcher:127.0.0.1:42495 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 994580 T5422 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 994580 T5422 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 994581 T5422 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 994584 T5422 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 994584 T5422 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 994592 T5433 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78c7fd1f name:ZooKeeperConnection Watcher:127.0.0.1:42495/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 994592 T5422 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 994592 T5422 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 994592 T5422 oascc.SolrZkClient.makePath makePath: /collections/collection1 [junit4] 2> 994595 T5422 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards [junit4] 2> 994597 T5422 oascc.SolrZkClient.makePath makePath: /collections/control_collection [junit4] 2> 994598 T5422 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards [junit4] 2> 994600 T5422 oasc.AbstractZkTestCase.putConfig put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 994600 T5422 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml [junit4] 2> 994604 T5422 oasc.AbstractZkTestCase.putConfig put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml [junit4] 2> 994604 T5422 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml [junit4] 2> 994608 T5422 oasc.AbstractZkTestCase.putConfig put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 994608 T5422 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 994610 T5422 oasc.AbstractZkTestCase.putConfig put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 994610 T5422 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt [junit4] 2> 994613 T5422 oasc.AbstractZkTestCase.putConfig put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 994613 T5422 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt [junit4] 2> 994615 T5422 oasc.AbstractZkTestCase.putConfig put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 994615 T5422 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml [junit4] 2> 994619 T5422 oasc.AbstractZkTestCase.putConfig put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 994619 T5422 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml [junit4] 2> 994621 T5422 oasc.AbstractZkTestCase.putConfig put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 994621 T5422 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json [junit4] 2> 994623 T5422 oasc.AbstractZkTestCase.putConfig put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 994623 T5422 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 994625 T5422 oasc.AbstractZkTestCase.putConfig put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 994625 T5422 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt [junit4] 2> 994627 T5422 oasc.AbstractZkTestCase.putConfig put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 994627 T5422 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt [junit4] 2> 994923 T5422 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores/collection1 [junit4] 2> 994925 T5422 oejs.Server.doStart jetty-9.2.10.v20150310 [junit4] 2> 994927 T5422 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@66a4bd00{/,null,AVAILABLE} [junit4] 2> 994930 T5422 oejs.AbstractConnector.doStart Started ServerConnector@7f684f4f{HTTP/1.1}{127.0.0.1:43640} [junit4] 2> 994930 T5422 oejs.Server.doStart Started @996438ms [junit4] 2> 994930 T5422 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores, hostContext=/, hostPort=43640} [junit4] 2> 994931 T5422 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@72b5615d [junit4] 2> 994931 T5422 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/' [junit4] 2> 994946 T5422 oasc.SolrXmlConfig.fromFile Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/solr.xml [junit4] 2> 994961 T5422 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores [junit4] 2> 994961 T5422 oasc.CoreContainer.<init> New CoreContainer 1931245704 [junit4] 2> 994961 T5422 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/] [junit4] 2> 994962 T5422 oasc.CoreContainer.load loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/lib [junit4] 2> 994962 T5422 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/lib). [junit4] 2> 994981 T5422 oashc.HttpShardHandlerFactory.init created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false, [junit4] 2> 994983 T5422 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 994983 T5422 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 994984 T5422 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 994984 T5422 oasc.CoreContainer.load Node Name: 127.0.0.1 [junit4] 2> 994984 T5422 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42495/solr [junit4] 2> 994984 T5422 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 994984 T5422 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 994986 T5422 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 994987 T5447 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71020ff3 name:ZooKeeperConnection Watcher:127.0.0.1:42495 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 994987 T5422 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 994988 T5422 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 994990 T5422 n:127.0.0.1:43640_ oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 994991 T5450 n:127.0.0.1:43640_ oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6372e3d9 name:ZooKeeperConnection Watcher:127.0.0.1:42495/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 994991 T5422 n:127.0.0.1:43640_ oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 994993 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 994995 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 994997 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 994999 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 995001 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 995003 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 995005 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 995006 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 995007 T5422 n:127.0.0.1:43640_ oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43640_ [junit4] 2> 995008 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43640_ [junit4] 2> 995010 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 995011 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 995013 T5422 n:127.0.0.1:43640_ oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 995014 T5422 n:127.0.0.1:43640_ oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:43640_ [junit4] 2> 995014 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 995016 T5422 n:127.0.0.1:43640_ oasc.Overseer.start Overseer (id=93880998667419651-127.0.0.1:43640_-n_0000000000) starting [junit4] 2> 995018 T5422 n:127.0.0.1:43640_ oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 995024 T5422 n:127.0.0.1:43640_ oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 995024 T5452 n:127.0.0.1:43640_ oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 995024 T5422 n:127.0.0.1:43640_ oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 995025 T5451 n:127.0.0.1:43640_ oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 995028 T5422 n:127.0.0.1:43640_ oasc.CoreContainer.initializeAuthenticationPlugin No authentication plugin used. [junit4] 2> 995029 T5422 n:127.0.0.1:43640_ oasc.CoreContainer.intializeAuthorizationPlugin Security conf doesn't exist. Skipping setup for authorization module. [junit4] 2> 995030 T5422 n:127.0.0.1:43640_ oasc.CorePropertiesLocator.discover Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores [junit4] 2> 995031 T5422 n:127.0.0.1:43640_ oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {collection=control_collection, shard=, schema=schema.xml, loadOnStartup=true, config=solrconfig.xml, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores/collection1/, name=collection1, dataDir=data/, coreNodeName=, transient=false, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores/collection1} [junit4] 2> 995031 T5422 n:127.0.0.1:43640_ oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores/collection1/ [junit4] 2> 995031 T5422 n:127.0.0.1:43640_ oasc.CorePropertiesLocator.discover Found 1 core definitions [junit4] 2> 995032 T5454 n:127.0.0.1:43640_ c:control_collection x:collection1 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection [junit4] 2> 995032 T5454 n:127.0.0.1:43640_ c:control_collection x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 995033 T5454 n:127.0.0.1:43640_ oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 995033 T5450 n:127.0.0.1:43640_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 995034 T5451 n:127.0.0.1:43640_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = { [junit4] 2> "state":"down", [junit4] 2> "collection":"control_collection", [junit4] 2> "base_url":"http://127.0.0.1:43640";, [junit4] 2> "node_name":"127.0.0.1:43640_", [junit4] 2> "numShards":"1", [junit4] 2> "roles":null, [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state", [junit4] 2> "shard":null} current state version: 0 [junit4] 2> 995035 T5451 n:127.0.0.1:43640_ oasco.ReplicaMutator.updateState Update state numShards=1 message={ [junit4] 2> "state":"down", [junit4] 2> "collection":"control_collection", [junit4] 2> "base_url":"http://127.0.0.1:43640";, [junit4] 2> "node_name":"127.0.0.1:43640_", [junit4] 2> "numShards":"1", [junit4] 2> "roles":null, [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state", [junit4] 2> "shard":null} [junit4] 2> 995035 T5451 n:127.0.0.1:43640_ oasco.ClusterStateMutator.createCollection building a new cName: control_collection [junit4] 2> 995035 T5451 n:127.0.0.1:43640_ oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1 [junit4] 2> 995036 T5450 n:127.0.0.1:43640_ 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> 996033 T5454 n:127.0.0.1:43640_ oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 996034 T5454 n:127.0.0.1:43640_ oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection [junit4] 2> 996034 T5454 n:127.0.0.1:43640_ oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 996035 T5454 n:127.0.0.1:43640_ oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 996035 T5454 n:127.0.0.1:43640_ oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 996036 T5454 n:127.0.0.1:43640_ oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores/collection1/' [junit4] 2> 996050 T5454 n:127.0.0.1:43640_ oasc.Config.<init> loaded config solrconfig.xml with version 0 [junit4] 2> 996056 T5454 n:127.0.0.1:43640_ oasc.SolrConfig.refreshRequestParams current version of requestparams : -1 [junit4] 2> 996069 T5454 n:127.0.0.1:43640_ oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.2.0 [junit4] 2> 996097 T5454 n:127.0.0.1:43640_ oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 996098 T5454 n:127.0.0.1:43640_ oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 996105 T5454 n:127.0.0.1:43640_ oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 996333 T5454 n:127.0.0.1:43640_ oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 996341 T5454 n:127.0.0.1:43640_ oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 996343 T5454 n:127.0.0.1:43640_ oass.IndexSchema.readSchema unique key field: id [junit4] 2> 996354 T5454 n:127.0.0.1:43640_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 996358 T5454 n:127.0.0.1:43640_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 996360 T5454 n:127.0.0.1:43640_ oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 996361 T5454 n:127.0.0.1:43640_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 996361 T5454 n:127.0.0.1:43640_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 996361 T5454 n:127.0.0.1:43640_ oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 996362 T5454 n:127.0.0.1:43640_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 996362 T5454 n:127.0.0.1:43640_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 996363 T5454 n:127.0.0.1:43640_ oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 996363 T5454 n:127.0.0.1:43640_ x:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 996363 T5454 n:127.0.0.1:43640_ x:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores/collection1/], dataDir=[null] [junit4] 2> 996363 T5454 n:127.0.0.1:43640_ x:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c78b84d [junit4] 2> 996364 T5454 n:127.0.0.1:43640_ x:collection1 oasc.CachingDirectoryFactory.get return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores/collection1/data [junit4] 2> 996364 T5454 n:127.0.0.1:43640_ x:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores/collection1/data/index/ [junit4] 2> 996364 T5454 n:127.0.0.1:43640_ x:collection1 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index... [junit4] 2> 996365 T5454 n:127.0.0.1:43640_ x:collection1 oasc.CachingDirectoryFactory.get return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/control-001/cores/collection1/data/index [junit4] 2> 996365 T5454 n:127.0.0.1:43640_ x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@d1b0f1a [junit4] 2> 996370 T5454 n:127.0.0.1:43640_ x:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(MMapDirectory@/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/index-MMapDirectory-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3998b70),segFN=segments_1,generation=1} [junit4] 2> 996370 T5454 n:127.0.0.1:43640_ x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 996375 T5454 n:127.0.0.1:43640_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 996375 T5454 n:127.0.0.1:43640_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 996376 T5454 n:127.0.0.1:43640_ x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 996376 T5454 n:127.0.0.1:43640_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 996376 T5454 n:127.0.0.1:43640_ x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 996376 T5454 n:127.0.0.1:43640_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 996377 T5454 n:127.0.0.1:43640_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 996377 T5454 n:127.0.0.1:43640_ x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 996377 T5454 n:127.0.0.1:43640_ x:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 996380 T5454 n:127.0.0.1:43640_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 996381 T5454 n:127.0.0.1:43640_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 996383 T5454 n:127.0.0.1:43640_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 996384 T5454 n:127.0.0.1:43640_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 996388 T5454 n:127.0.0.1:43640_ x:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/plugins,standard,/admin/ping,/schema,/admin/luke,/admin/segments,/update/csv,/admin/mbeans,/admin/logging,/admin/properties,/admin/file,/replication,/update/json,/admin/threads,/config,/update,/admin/system,/get,/update/json/docs [junit4] 2> 996389 T5454 n:127.0.0.1:43640_ x:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache [junit4] 2> 996390 T5454 n:127.0.0.1:43640_ x:collection1 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 996390 T5454 n:127.0.0.1:43640_ x:collection1 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 996391 T5454 n:127.0.0.1:43640_ x:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 996391 T5454 n:127.0.0.1:43640_ x:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 996391 T5454 n:127.0.0.1:43640_ x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=60.8564453125, floorSegmentMB=2.087890625, forceMergeDeletesPctAllowed=11.56301917677912, segmentsPerTier=46.0, maxCFSSegmentSizeMB=1.8935546875, noCFSRatio=1.0 [junit4] 2> 996394 T5454 n:127.0.0.1:43640_ x:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(MMapDirectory@/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/index-MMapDirectory-001 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3998b70),segFN=segments_1,generation=1} [junit4] 2> 996394 T5454 n:127.0.0.1:43640_ x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 996394 T5454 n:127.0.0.1:43640_ x:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@1f0d01da[collection1] main [junit4] 2> 996394 T5454 n:127.0.0.1:43640_ x:collection1 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 996395 T5454 n:127.0.0.1:43640_ x:collection1 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 996395 T5454 n:127.0.0.1:43640_ x:collection1 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 996396 T5454 n:127.0.0.1:43640_ x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 996396 T5454 n:127.0.0.1:43640_ x:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 996396 T5454 n:127.0.0.1:43640_ x:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 996397 T5454 n:127.0.0.1:43640_ x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json [junit4] 2> 996397 T5454 n:127.0.0.1:43640_ x:collection1 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 996397 T5454 n:127.0.0.1:43640_ x:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 996397 T5454 n:127.0.0.1:43640_ x:collection1 oash.ReplicationHandler.inform Commits will be reserved for 10000 [junit4] 2> 996398 T5454 n:127.0.0.1:43640_ x:collection1 oasc.ZkController.getConfDirListeners watch zkdir /configs/conf1 [junit4] 2> 996398 T5455 n:127.0.0.1:43640_ x:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f0d01da[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 996398 T5454 n:127.0.0.1:43640_ x:collection1 oasu.UpdateLog.onFirstSearcher On first searcher opened, looking up max value of version field [junit4] 2> 996398 T5454 n:127.0.0.1:43640_ x:collection1 oasu.VersionInfo.getMaxVersionFromIndex Refreshing highest value of _version_ for 65536 version buckets from index [junit4] 2> 996398 T5454 n:127.0.0.1:43640_ x:collection1 oasu.VersionInfo.getMaxVersionFromIndex No terms found for _version_, cannot seed version bucket highest value from index [junit4] 2> 996399 T5454 n:127.0.0.1:43640_ x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion Could not find max version in index or recent updates, using new clock 1502095980693028864 [junit4] 2> 996401 T5454 n:127.0.0.1:43640_ x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion Took 3 ms to seed version buckets with highest version 1502095980693028864 [junit4] 2> 996401 T5454 n:127.0.0.1:43640_ x:collection1 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 996402 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43640 collection:control_collection shard:shard1 [junit4] 2> 996402 T5422 n:127.0.0.1:43640_ oass.SolrDispatchFilter.init user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1 [junit4] 2> 996402 T5422 n:127.0.0.1:43640_ oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 996403 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election [junit4] 2> 996404 T5422 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 996404 T5422 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 996406 T5461 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ecb19dd name:ZooKeeperConnection Watcher:127.0.0.1:42495/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 996406 T5422 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 996406 T5422 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 996407 T5422 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 996409 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 996410 T5422 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 996411 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 996411 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C1067 name=collection1 org.apache.solr.core.SolrCore@66034621 url=http://127.0.0.1:43640/collection1 node=127.0.0.1:43640_ C1067_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:43640, node_name=127.0.0.1:43640_, core=collection1} [junit4] 2> 996411 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 C1067 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43640/collection1/ [junit4] 2> 996411 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 C1067 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 996412 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 C1067 oasc.SyncStrategy.syncToMe http://127.0.0.1:43640/collection1/ has no replicas [junit4] 2> 996412 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43640/collection1/ shard1 [junit4] 2> 996412 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1 [junit4] 2> 996416 T5450 n:127.0.0.1:43640_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 996417 T5451 n:127.0.0.1:43640_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 2, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection"} current state version: 1 [junit4] 2> 996420 T5451 n:127.0.0.1:43640_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection", [junit4] 2> "base_url":"http://127.0.0.1:43640";, [junit4] 2> "core":"collection1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 996421 T5450 n:127.0.0.1:43640_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 996523 T5450 n:127.0.0.1:43640_ 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> 996523 T5461 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> 996567 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oasc.ZkController.register We are http://127.0.0.1:43640/collection1/ and leader is http://127.0.0.1:43640/collection1/ [junit4] 2> 996567 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43640 [junit4] 2> 996567 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 996568 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection [junit4] 2> 996568 T5458 n:127.0.0.1:43640_ c:control_collection s:shard1 x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 996569 T5450 n:127.0.0.1:43640_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 996570 T5451 n:127.0.0.1:43640_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = { [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "state":"active", [junit4] 2> "collection":"control_collection", [junit4] 2> "base_url":"http://127.0.0.1:43640";, [junit4] 2> "node_name":"127.0.0.1:43640_", [junit4] 2> "numShards":"2", [junit4] 2> "roles":null, [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state", [junit4] 2> "shard":"shard1"} current state version: 2 [junit4] 2> 996571 T5451 n:127.0.0.1:43640_ oasco.ReplicaMutator.updateState Update state numShards=2 message={ [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "state":"active", [junit4] 2> "collection":"control_collection", [junit4] 2> "base_url":"http://127.0.0.1:43640";, [junit4] 2> "node_name":"127.0.0.1:43640_", [junit4] 2> "numShards":"2", [junit4] 2> "roles":null, [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state", [junit4] 2> "shard":"shard1"} [junit4] 2> 996674 T5461 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> 996674 T5450 n:127.0.0.1:43640_ 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> 996713 T5422 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores/collection1 [junit4] 2> 996714 T5422 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001 [junit4] 2> 996715 T5422 oejs.Server.doStart jetty-9.2.10.v20150310 [junit4] 2> 996717 T5422 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@5d9da337{/,null,AVAILABLE} [junit4] 2> 996718 T5422 oejs.AbstractConnector.doStart Started ServerConnector@44ab7fd6{HTTP/1.1}{127.0.0.1:37737} [junit4] 2> 996718 T5422 oejs.Server.doStart Started @998226ms [junit4] 2> 996718 T5422 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solrconfig=solrconfig.xml, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores, hostContext=/, hostPort=37737} [junit4] 2> 996719 T5422 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@72b5615d [junit4] 2> 996719 T5422 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/' [junit4] 2> 996734 T5422 oasc.SolrXmlConfig.fromFile Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/solr.xml [junit4] 2> 996748 T5422 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores [junit4] 2> 996749 T5422 oasc.CoreContainer.<init> New CoreContainer 1901302828 [junit4] 2> 996749 T5422 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/] [junit4] 2> 996749 T5422 oasc.CoreContainer.load loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/lib [junit4] 2> 996749 T5422 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/lib). [junit4] 2> 996757 T5422 oashc.HttpShardHandlerFactory.init created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false, [junit4] 2> 996758 T5422 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 996759 T5422 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 996759 T5422 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 996759 T5422 oasc.CoreContainer.load Node Name: 127.0.0.1 [junit4] 2> 996760 T5422 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42495/solr [junit4] 2> 996760 T5422 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 996760 T5422 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 996761 T5422 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 996763 T5475 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@695f370c name:ZooKeeperConnection Watcher:127.0.0.1:42495 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 996764 T5422 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 996764 T5422 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 996766 T5422 n:127.0.0.1:37737_ oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 996768 T5478 n:127.0.0.1:37737_ oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ea89f24 name:ZooKeeperConnection Watcher:127.0.0.1:42495/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 996768 T5422 n:127.0.0.1:37737_ oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 996773 T5422 n:127.0.0.1:37737_ oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 997778 T5422 n:127.0.0.1:37737_ oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37737_ [junit4] 2> 997779 T5422 n:127.0.0.1:37737_ oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37737_ [junit4] 2> 997784 T5422 n:127.0.0.1:37737_ oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 997786 T5422 n:127.0.0.1:37737_ oasc.CoreContainer.initializeAuthenticationPlugin No authentication plugin used. [junit4] 2> 997787 T5422 n:127.0.0.1:37737_ oasc.CoreContainer.intializeAuthorizationPlugin Security conf doesn't exist. Skipping setup for authorization module. [junit4] 2> 997788 T5422 n:127.0.0.1:37737_ oasc.CorePropertiesLocator.discover Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores [junit4] 2> 997789 T5422 n:127.0.0.1:37737_ oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {shard=, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores/collection1/, schema=schema.xml, transient=false, loadOnStartup=true, name=collection1, config=solrconfig.xml, dataDir=data/, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores/collection1, coreNodeName=, collection=collection1} [junit4] 2> 997789 T5422 n:127.0.0.1:37737_ oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores/collection1/ [junit4] 2> 997790 T5422 n:127.0.0.1:37737_ oasc.CorePropertiesLocator.discover Found 1 core definitions [junit4] 2> 997791 T5479 n:127.0.0.1:37737_ c:collection1 x:collection1 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 997791 T5479 n:127.0.0.1:37737_ c:collection1 x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 997792 T5479 n:127.0.0.1:37737_ oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 997792 T5450 n:127.0.0.1:43640_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 997794 T5451 n:127.0.0.1:43640_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = { [junit4] 2> "state":"down", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:37737";, [junit4] 2> "node_name":"127.0.0.1:37737_", [junit4] 2> "numShards":"2", [junit4] 2> "roles":null, [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state", [junit4] 2> "shard":null} current state version: 3 [junit4] 2> 997794 T5451 n:127.0.0.1:43640_ oasco.ReplicaMutator.updateState Update state numShards=2 message={ [junit4] 2> "state":"down", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:37737";, [junit4] 2> "node_name":"127.0.0.1:37737_", [junit4] 2> "numShards":"2", [junit4] 2> "roles":null, [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state", [junit4] 2> "shard":null} [junit4] 2> 997795 T5451 n:127.0.0.1:43640_ oasco.ClusterStateMutator.createCollection building a new cName: collection1 [junit4] 2> 997795 T5451 n:127.0.0.1:43640_ oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1 [junit4] 2> 997898 T5450 n:127.0.0.1:43640_ 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> 997898 T5461 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> 997898 T5478 n:127.0.0.1:37737_ 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> 998793 T5479 n:127.0.0.1:37737_ oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 998793 T5479 n:127.0.0.1:37737_ oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 998794 T5479 n:127.0.0.1:37737_ oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 998794 T5479 n:127.0.0.1:37737_ oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 998795 T5479 n:127.0.0.1:37737_ oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 998795 T5479 n:127.0.0.1:37737_ oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores/collection1/' [junit4] 2> 998812 T5479 n:127.0.0.1:37737_ oasc.Config.<init> loaded config solrconfig.xml with version 0 [junit4] 2> 998819 T5479 n:127.0.0.1:37737_ oasc.SolrConfig.refreshRequestParams current version of requestparams : -1 [junit4] 2> 998834 T5479 n:127.0.0.1:37737_ oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.2.0 [junit4] 2> 998867 T5479 n:127.0.0.1:37737_ oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 998868 T5479 n:127.0.0.1:37737_ oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 998876 T5479 n:127.0.0.1:37737_ oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 999149 T5479 n:127.0.0.1:37737_ oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 999159 T5479 n:127.0.0.1:37737_ oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 999161 T5479 n:127.0.0.1:37737_ oass.IndexSchema.readSchema unique key field: id [junit4] 2> 999172 T5479 n:127.0.0.1:37737_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 999175 T5479 n:127.0.0.1:37737_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 999178 T5479 n:127.0.0.1:37737_ oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 999179 T5479 n:127.0.0.1:37737_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 999179 T5479 n:127.0.0.1:37737_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 999179 T5479 n:127.0.0.1:37737_ oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 999180 T5479 n:127.0.0.1:37737_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 999181 T5479 n:127.0.0.1:37737_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 999181 T5479 n:127.0.0.1:37737_ oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 999181 T5479 n:127.0.0.1:37737_ x:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 999181 T5479 n:127.0.0.1:37737_ x:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores/collection1/], dataDir=[null] [junit4] 2> 999182 T5479 n:127.0.0.1:37737_ x:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c78b84d [junit4] 2> 999182 T5479 n:127.0.0.1:37737_ x:collection1 oasc.CachingDirectoryFactory.get return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores/collection1/data [junit4] 2> 999182 T5479 n:127.0.0.1:37737_ x:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores/collection1/data/index/ [junit4] 2> 999183 T5479 n:127.0.0.1:37737_ x:collection1 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores/collection1/data/index' doesn't exist. Creating new index... [junit4] 2> 999184 T5479 n:127.0.0.1:37737_ x:collection1 oasc.CachingDirectoryFactory.get return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-1-001/cores/collection1/data/index [junit4] 2> 999184 T5479 n:127.0.0.1:37737_ x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@96662fb [junit4] 2> 999190 T5479 n:127.0.0.1:37737_ x:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(MMapDirectory@/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/index-MMapDirectory-002 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3998b70),segFN=segments_1,generation=1} [junit4] 2> 999190 T5479 n:127.0.0.1:37737_ x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 999196 T5479 n:127.0.0.1:37737_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 999196 T5479 n:127.0.0.1:37737_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 999197 T5479 n:127.0.0.1:37737_ x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 999197 T5479 n:127.0.0.1:37737_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 999197 T5479 n:127.0.0.1:37737_ x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 999197 T5479 n:127.0.0.1:37737_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 999198 T5479 n:127.0.0.1:37737_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 999198 T5479 n:127.0.0.1:37737_ x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 999198 T5479 n:127.0.0.1:37737_ x:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 999202 T5479 n:127.0.0.1:37737_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 999203 T5479 n:127.0.0.1:37737_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 999205 T5479 n:127.0.0.1:37737_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 999206 T5479 n:127.0.0.1:37737_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 999213 T5479 n:127.0.0.1:37737_ x:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/plugins,standard,/admin/ping,/schema,/admin/luke,/admin/segments,/update/csv,/admin/mbeans,/admin/logging,/admin/properties,/admin/file,/replication,/update/json,/admin/threads,/config,/update,/admin/system,/get,/update/json/docs [junit4] 2> 999229 T5479 n:127.0.0.1:37737_ x:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache [junit4] 2> 999229 T5479 n:127.0.0.1:37737_ x:collection1 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 999230 T5479 n:127.0.0.1:37737_ x:collection1 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 999231 T5479 n:127.0.0.1:37737_ x:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 999231 T5479 n:127.0.0.1:37737_ x:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 999232 T5479 n:127.0.0.1:37737_ x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=60.8564453125, floorSegmentMB=2.087890625, forceMergeDeletesPctAllowed=11.56301917677912, segmentsPerTier=46.0, maxCFSSegmentSizeMB=1.8935546875, noCFSRatio=1.0 [junit4] 2> 999234 T5479 n:127.0.0.1:37737_ x:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(MMapDirectory@/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/index-MMapDirectory-002 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3998b70),segFN=segments_1,generation=1} [junit4] 2> 999235 T5479 n:127.0.0.1:37737_ x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 999235 T5479 n:127.0.0.1:37737_ x:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@73249126[collection1] main [junit4] 2> 999235 T5479 n:127.0.0.1:37737_ x:collection1 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 999236 T5479 n:127.0.0.1:37737_ x:collection1 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 999236 T5479 n:127.0.0.1:37737_ x:collection1 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 999237 T5479 n:127.0.0.1:37737_ x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 999237 T5479 n:127.0.0.1:37737_ x:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 999237 T5479 n:127.0.0.1:37737_ x:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 999238 T5479 n:127.0.0.1:37737_ x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json [junit4] 2> 999238 T5479 n:127.0.0.1:37737_ x:collection1 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 999238 T5479 n:127.0.0.1:37737_ x:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 999239 T5479 n:127.0.0.1:37737_ x:collection1 oash.ReplicationHandler.inform Commits will be reserved for 10000 [junit4] 2> 999239 T5480 n:127.0.0.1:37737_ x:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@73249126[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 999240 T5479 n:127.0.0.1:37737_ x:collection1 oasc.ZkController.getConfDirListeners watch zkdir /configs/conf1 [junit4] 2> 999240 T5479 n:127.0.0.1:37737_ x:collection1 oasu.UpdateLog.onFirstSearcher On first searcher opened, looking up max value of version field [junit4] 2> 999241 T5479 n:127.0.0.1:37737_ x:collection1 oasu.VersionInfo.getMaxVersionFromIndex Refreshing highest value of _version_ for 65536 version buckets from index [junit4] 2> 999241 T5479 n:127.0.0.1:37737_ x:collection1 oasu.VersionInfo.getMaxVersionFromIndex No terms found for _version_, cannot seed version bucket highest value from index [junit4] 2> 999241 T5479 n:127.0.0.1:37737_ x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion Could not find max version in index or recent updates, using new clock 1502095983673081856 [junit4] 2> 999243 T5479 n:127.0.0.1:37737_ x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion Took 2 ms to seed version buckets with highest version 1502095983673081856 [junit4] 2> 999244 T5479 n:127.0.0.1:37737_ x:collection1 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 999245 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37737 collection:collection1 shard:shard1 [junit4] 2> 999245 T5422 n:127.0.0.1:37737_ oass.SolrDispatchFilter.init user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1 [junit4] 2> 999245 T5422 n:127.0.0.1:37737_ oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 999246 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 999251 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 999252 T5450 n:127.0.0.1:43640_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 999253 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 999253 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> 999253 T5451 n:127.0.0.1:43640_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1"} current state version: 4 [junit4] 2> ASYNC NEW_CORE C1068 name=collection1 org.apache.solr.core.SolrCore@5975e82f url=http://127.0.0.1:37737/collection1 node=127.0.0.1:37737_ C1068_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:37737, node_name=127.0.0.1:37737_, core=collection1} [junit4] 2> 999253 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 C1068 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37737/collection1/ [junit4] 2> 999253 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 C1068 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 999254 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 C1068 oasc.SyncStrategy.syncToMe http://127.0.0.1:37737/collection1/ has no replicas [junit4] 2> 999254 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37737/collection1/ shard1 [junit4] 2> 999254 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 999257 T5450 n:127.0.0.1:43640_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 999258 T5451 n:127.0.0.1:43640_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:37737";, [junit4] 2> "core":"collection1", [junit4] 2> "state":"active"} current state version: 4 [junit4] 2> 999361 T5461 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> 999361 T5478 n:127.0.0.1:37737_ 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> 999361 T5450 n:127.0.0.1:43640_ 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> 999409 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oasc.ZkController.register We are http://127.0.0.1:37737/collection1/ and leader is http://127.0.0.1:37737/collection1/ [junit4] 2> 999409 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37737 [junit4] 2> 999409 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 999410 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 999410 T5483 n:127.0.0.1:37737_ c:collection1 s:shard1 x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 999411 T5450 n:127.0.0.1:43640_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 999412 T5451 n:127.0.0.1:43640_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = { [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "state":"active", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:37737";, [junit4] 2> "node_name":"127.0.0.1:37737_", [junit4] 2> "numShards":"2", [junit4] 2> "roles":null, [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state", [junit4] 2> "shard":"shard1"} current state version: 5 [junit4] 2> 999413 T5451 n:127.0.0.1:43640_ oasco.ReplicaMutator.updateState Update state numShards=2 message={ [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "state":"active", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:37737";, [junit4] 2> "node_name":"127.0.0.1:37737_", [junit4] 2> "numShards":"2", [junit4] 2> "roles":null, [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state", [junit4] 2> "shard":"shard1"} [junit4] 2> 999516 T5450 n:127.0.0.1:43640_ 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> 999516 T5461 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> 999516 T5478 n:127.0.0.1:37737_ 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> 999546 T5422 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/cores/collection1 [junit4] 2> 999547 T5422 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001 [junit4] 2> 999548 T5422 oejs.Server.doStart jetty-9.2.10.v20150310 [junit4] 2> 999550 T5422 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@31d28105{/,null,AVAILABLE} [junit4] 2> 999551 T5422 oejs.AbstractConnector.doStart Started ServerConnector@49224ab6{HTTP/1.1}{127.0.0.1:38867} [junit4] 2> 999551 T5422 oejs.Server.doStart Started @1001059ms [junit4] 2> 999551 T5422 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solrconfig=solrconfig.xml, hostPort=38867, hostContext=/, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/cores} [junit4] 2> 999552 T5422 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@72b5615d [junit4] 2> 999552 T5422 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/' [junit4] 2> 999567 T5422 oasc.SolrXmlConfig.fromFile Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/solr.xml [junit4] 2> 999581 T5422 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/cores [junit4] 2> 999582 T5422 oasc.CoreContainer.<init> New CoreContainer 1391447765 [junit4] 2> 999582 T5422 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/] [junit4] 2> 999582 T5422 oasc.CoreContainer.load loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/lib [junit4] 2> 999583 T5422 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/lib). [junit4] 2> 999590 T5422 oashc.HttpShardHandlerFactory.init created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false, [junit4] 2> 999591 T5422 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 999592 T5422 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 999592 T5422 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 999593 T5422 oasc.CoreContainer.load Node Name: 127.0.0.1 [junit4] 2> 999593 T5422 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42495/solr [junit4] 2> 999593 T5422 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 999593 T5422 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 999594 T5422 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 999595 T5497 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47ad9f52 name:ZooKeeperConnection Watcher:127.0.0.1:42495 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 999596 T5422 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 999597 T5422 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 999599 T5422 n:127.0.0.1:38867_ oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 999600 T5500 n:127.0.0.1:38867_ oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f039a28 name:ZooKeeperConnection Watcher:127.0.0.1:42495/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 999600 T5422 n:127.0.0.1:38867_ oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 999605 T5422 n:127.0.0.1:38867_ oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1000610 T5422 n:127.0.0.1:38867_ oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38867_ [junit4] 2> 1000611 T5422 n:127.0.0.1:38867_ oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38867_ [junit4] 2> 1000618 T5422 n:127.0.0.1:38867_ oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 1000621 T5422 n:127.0.0.1:38867_ oasc.CoreContainer.initializeAuthenticationPlugin No authentication plugin used. [junit4] 2> 1000622 T5422 n:127.0.0.1:38867_ oasc.CoreContainer.intializeAuthorizationPlugin Security conf doesn't exist. Skipping setup for authorization module. [junit4] 2> 1000624 T5422 n:127.0.0.1:38867_ oasc.CorePropertiesLocator.discover Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/cores [junit4] 2> 1000626 T5422 n:127.0.0.1:38867_ oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {schema=schema.xml, transient=false, loadOnStartup=true, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/cores/collection1/, collection=collection1, config=solrconfig.xml, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/cores/collection1, name=collection1, shard=, coreNodeName=, dataDir=data/} [junit4] 2> 1000627 T5422 n:127.0.0.1:38867_ oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/cores/collection1/ [junit4] 2> 1000627 T5422 n:127.0.0.1:38867_ oasc.CorePropertiesLocator.discover Found 1 core definitions [junit4] 2> 1000629 T5501 n:127.0.0.1:38867_ c:collection1 x:collection1 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 1000629 T5501 n:127.0.0.1:38867_ c:collection1 x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 1000630 T5450 n:127.0.0.1:43640_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 1000631 T5501 n:127.0.0.1:38867_ oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 1000631 T5451 n:127.0.0.1:43640_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = { [junit4] 2> "state":"down", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:38867";, [junit4] 2> "node_name":"127.0.0.1:38867_", [junit4] 2> "numShards":"2", [junit4] 2> "roles":null, [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state", [junit4] 2> "shard":null} current state version: 6 [junit4] 2> 1000632 T5451 n:127.0.0.1:43640_ oasco.ReplicaMutator.updateState Update state numShards=2 message={ [junit4] 2> "state":"down", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:38867";, [junit4] 2> "node_name":"127.0.0.1:38867_", [junit4] 2> "numShards":"2", [junit4] 2> "roles":null, [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state", [junit4] 2> "shard":null} [junit4] 2> 1000632 T5451 n:127.0.0.1:43640_ oasco.ReplicaMutator.updateState Collection already exists with numShards=2 [junit4] 2> 1000633 T5451 n:127.0.0.1:43640_ oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard2 [junit4] 2> 1000737 T5500 n:127.0.0.1:38867_ 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> 1000737 T5461 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> 1000737 T5478 n:127.0.0.1:37737_ 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> 1000737 T5450 n:127.0.0.1:43640_ 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> 1001631 T5501 n:127.0.0.1:38867_ oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 1001632 T5501 n:127.0.0.1:38867_ oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 1001633 T5501 n:127.0.0.1:38867_ oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 1001633 T5501 n:127.0.0.1:38867_ oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 1001635 T5501 n:127.0.0.1:38867_ oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 1001635 T5501 n:127.0.0.1:38867_ oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/cores/collection1/' [junit4] 2> 1001656 T5501 n:127.0.0.1:38867_ oasc.Config.<init> loaded config solrconfig.xml with version 0 [junit4] 2> 1001663 T5501 n:127.0.0.1:38867_ oasc.SolrConfig.refreshRequestParams current version of requestparams : -1 [junit4] 2> 1001679 T5501 n:127.0.0.1:38867_ oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.2.0 [junit4] 2> 1001712 T5501 n:127.0.0.1:38867_ oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 1001714 T5501 n:127.0.0.1:38867_ oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 1001721 T5501 n:127.0.0.1:38867_ oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 1001995 T5501 n:127.0.0.1:38867_ oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 1002005 T5501 n:127.0.0.1:38867_ oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 1002007 T5501 n:127.0.0.1:38867_ oass.IndexSchema.readSchema unique key field: id [junit4] 2> 1002020 T5501 n:127.0.0.1:38867_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 1002024 T5501 n:127.0.0.1:38867_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 1002028 T5501 n:127.0.0.1:38867_ oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 1002030 T5501 n:127.0.0.1:38867_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 1002030 T5501 n:127.0.0.1:38867_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 1002030 T5501 n:127.0.0.1:38867_ oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 1002031 T5501 n:127.0.0.1:38867_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 1002031 T5501 n:127.0.0.1:38867_ oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 1002032 T5501 n:127.0.0.1:38867_ oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 1002032 T5501 n:127.0.0.1:38867_ x:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 1002032 T5501 n:127.0.0.1:38867_ x:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest 2418605820CD177C-001/shard-2-001/cores/collection1/], dataDir=[null] [junit4] 2> 1002032 T5501 n:127.0.0.1:38867_ x:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c78b84d [junit4] 2> 1002033 T5501 n:127.0.0.1:38867_ x:collection1 oasc.CachingDirectoryFactory.get return new directory for /x1/jenkins/jenkins [...truncated too long message...] at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799) [junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220) [junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:884)Throwable #4: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=5759, name=collection1, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] [junit4] > Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:46708: Could not find collection : awholynewstresscollection_collection1_0 [junit4] > at __randomizedtesting.SeedInfo.seed([2418605820CD177C]:0) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799) [junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220) [junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:884)Throwable #5: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=5761, name=collection3, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] [junit4] > Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:46682: collection already exists: awholynewstresscollection_collection3_1 [junit4] > at __randomizedtesting.SeedInfo.seed([2418605820CD177C]:0) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799) [junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220) [junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1621) [junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1642) [junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:877)Throwable #6: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=5758, name=collection0, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] [junit4] > Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:46682: Could not find collection : awholynewstresscollection_collection0_1 [junit4] > at __randomizedtesting.SeedInfo.seed([2418605820CD177C]:0) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799) [junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220) [junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:884) [junit4] 2> 1281786 T5422 c:collection1 s:shard1 x:collection1 oas.SolrTestCaseJ4.deleteCore ###deleteCore [junit4] 2> NOTE: test params are: codec=DummyCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=DUMMY, chunkSize=1, maxDocsPerChunk=2, blockSize=723), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=DUMMY, chunkSize=1, blockSize=723)), sim=DefaultSimilarity, locale=ja_JP, timezone=Etc/GMT-8 [junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.7.0_72 (64-bit)/cpus=4,threads=1,free=239976240,total=510132224 [junit4] 2> NOTE: All tests run in this JVM: [TestOmitPositions, CoreAdminHandlerTest, IndexSchemaRuntimeFieldTest, FieldMutatingUpdateProcessorTest, MergeStrategyTest, SuggesterTSTTest, LukeRequestHandlerTest, TestSchemaResource, TestFastWriter, DocExpirationUpdateProcessorFactoryTest, DisMaxRequestHandlerTest, EchoParamsTest, TestTolerantSearch, TestSerializedLuceneMatchVersion, BasicFunctionalityTest, TestCoreContainer, SuggestComponentTest, TestCoreDiscovery, FacetPivotSmallTest, VMParamsZkACLAndCredentialsProvidersTest, TestFieldTypeCollectionResource, HdfsNNFailoverTest, DirectSolrConnectionTest, SimpleMLTQParserTest, TestClassNameShortening, TestSolrQueryParserResource, CoreAdminCreateDiscoverTest, ConvertedLegacyTest, CopyFieldTest, TestHashPartitioner, TestRTGBase, WordBreakSolrSpellCheckerTest, TestMacros, CurrencyFieldOpenExchangeTest, DistributedVersionInfoTest, TestIntervalFaceting, TestSolrCloudWithKerberos, TestAtomicUpdateErrorCases, TestElisionMultitermQuery, TestCharFilters, CachingDirectoryFactoryTest, UpdateParamsTest, TestFreeTextSuggestions, NoCacheHeaderTest, DocumentAnalysisRequestHandlerTest, SolrCmdDistributorTest, DistributedTermsComponentTest, TestIndexSearcher, TestPHPSerializedResponseWriter, IgnoreCommitOptimizeUpdateProcessorFactoryTest, DeleteReplicaTest, SpellCheckComponentTest, PreAnalyzedFieldTest, SpellingQueryConverterTest, TestObjectReleaseTracker, TestLMJelinekMercerSimilarityFactory, TestCustomSort, TestNamedUpdateProcessors, DeleteInactiveReplicaTest, JsonLoaderTest, RAMDirectoryFactoryTest, SolrPluginUtilsTest, ShowFileRequestHandlerTest, DocValuesMultiTest, CoreAdminRequestStatusTest, TestSchemaNameResource, TestRebalanceLeaders, FieldAnalysisRequestHandlerTest, SharedFSAutoReplicaFailoverUtilsTest, ClusterStateUpdateTest, CacheHeaderTest, TestDistributedMissingSort, TestStressUserVersions, TestManagedSynonymFilterFactory, ShardRoutingCustomTest, TestRemoveLastDynamicCopyField, AnalysisAfterCoreReloadTest, DistanceFunctionTest, DistanceUnitsTest, TestJsonFacets, TestSortingResponseWriter, BadComponentTest, TestChildDocTransformer, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest] [junit4] Completed [157/496] on J1 in 288.17s, 1 test, 1 error <<< FAILURES! [...truncated 1075 lines...] BUILD FAILED /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/build.xml:543: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/build.xml:484: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/build.xml:61: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/extra-targets.xml:39: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/build.xml:229: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/solr/common-build.xml:511: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/lucene/common-build.xml:1433: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.2/lucene/common-build.xml:991: There were test failures: 496 suites, 1973 tests, 1 error, 51 ignored (10 assumptions) Total time: 168 minutes 48 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts No prior successful build to compare, so performing full copy of artifacts Recording test results Email was triggered for: Failure Sending email for trigger: Failure
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
