You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/11/07 06:35:32 UTC
[JENKINS] Lucene-Solr-5.x-Linux (32bit/jdk1.7.0_67) - Build # 11417
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.x-Linux/11417/
Java: 32bit/jdk1.7.0_67 -server -XX:+UseParallelGC (asserts: false)
1 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.MultiThreadedOCPTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.MultiThreadedOCPTest: 1) Thread[id=7594, name=OverseerThreadFactory-4096-thread-5, state=TIMED_WAITING, group=Overseer collection creation process.] at java.lang.Thread.sleep(Native Method) at org.apache.solr.cloud.OverseerCollectionProcessor.waitForCoreNodeName(OverseerCollectionProcessor.java:1847) at org.apache.solr.cloud.OverseerCollectionProcessor.splitShard(OverseerCollectionProcessor.java:1729) at org.apache.solr.cloud.OverseerCollectionProcessor.processMessage(OverseerCollectionProcessor.java:615) at org.apache.solr.cloud.OverseerCollectionProcessor$Runner.run(OverseerCollectionProcessor.java:2856) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.MultiThreadedOCPTest:
1) Thread[id=7594, name=OverseerThreadFactory-4096-thread-5, state=TIMED_WAITING, group=Overseer collection creation process.]
at java.lang.Thread.sleep(Native Method)
at org.apache.solr.cloud.OverseerCollectionProcessor.waitForCoreNodeName(OverseerCollectionProcessor.java:1847)
at org.apache.solr.cloud.OverseerCollectionProcessor.splitShard(OverseerCollectionProcessor.java:1729)
at org.apache.solr.cloud.OverseerCollectionProcessor.processMessage(OverseerCollectionProcessor.java:615)
at org.apache.solr.cloud.OverseerCollectionProcessor$Runner.run(OverseerCollectionProcessor.java:2856)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
at __randomizedtesting.SeedInfo.seed([CE6D0732FFA7EB0D]:0)
Build Log:
[...truncated 12197 lines...]
[junit4] Suite: org.apache.solr.cloud.MultiThreadedOCPTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/init-core-data-001
[junit4] 2> 2501531 T7405 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
[junit4] 2> 2501531 T7405 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 2501534 T7405 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 2501535 T7405 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2501535 T7406 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2501635 T7405 oasc.ZkTestServer.run start zk server on port:42482
[junit4] 2> 2501636 T7405 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2501636 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2501638 T7412 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ff4994 name:ZooKeeperConnection Watcher:127.0.0.1:42482 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2501638 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2501639 T7405 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2501639 T7405 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2501641 T7405 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2501642 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2501643 T7414 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27c6fe name:ZooKeeperConnection Watcher:127.0.0.1:42482/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2501643 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2501643 T7405 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2501644 T7405 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 2501645 T7405 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 2501647 T7405 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 2501648 T7405 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 2501649 T7405 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 2501649 T7405 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 2501651 T7405 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 2501651 T7405 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 2501653 T7405 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2501653 T7405 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2501654 T7405 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 2501655 T7405 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 2501656 T7405 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 2501657 T7405 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 2501658 T7405 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 2501658 T7405 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 2501660 T7405 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 2501660 T7405 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 2501661 T7405 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 2501662 T7405 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 2501663 T7405 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2501664 T7405 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2501665 T7405 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 2501665 T7405 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 2501667 T7405 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 2501667 T7405 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 2501669 T7405 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2501670 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2501670 T7416 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@97923a name:ZooKeeperConnection Watcher:127.0.0.1:42482/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2501670 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2501671 T7405 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2501893 T7405 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2501896 T7405 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 2501897 T7405 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:45925
[junit4] 2> 2501898 T7405 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2501898 T7405 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2501899 T7405 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002
[junit4] 2> 2501899 T7405 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/'
[junit4] 2> 2501909 T7405 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/solr.xml
[junit4] 2> 2501933 T7405 oasc.CoreContainer.<init> New CoreContainer 4350368
[junit4] 2> 2501933 T7405 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/]
[junit4] 2> 2501934 T7405 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2501934 T7405 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2501935 T7405 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2501935 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2501935 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
[junit4] 2> 2501935 T7405 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2501936 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2501936 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2501936 T7405 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2501937 T7405 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2501938 T7405 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 2501939 T7405 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2501939 T7405 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2501939 T7405 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2501939 T7405 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42482/solr
[junit4] 2> 2501940 T7405 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2501940 T7405 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2501941 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2501942 T7427 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@202611 name:ZooKeeperConnection Watcher:127.0.0.1:42482 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2501942 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2501942 T7405 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2501943 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2501944 T7429 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8f99b6 name:ZooKeeperConnection Watcher:127.0.0.1:42482/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2501944 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2501945 T7405 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2501947 T7405 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2501948 T7405 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2501950 T7405 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2501951 T7405 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2501953 T7405 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2501953 T7405 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45925_
[junit4] 2> 2501954 T7405 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45925_
[junit4] 2> 2501955 T7405 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2501956 T7405 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2501957 T7405 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 2501958 T7405 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:45925_
[junit4] 2> 2501958 T7405 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2501959 T7405 oasc.Overseer.start Overseer (id=92755581012410372-127.0.0.1:45925_-n_0000000000) starting
[junit4] 2> 2501961 T7405 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2501965 T7405 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 2501966 T7431 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2501966 T7430 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2501966 T7405 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2501967 T7405 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2501968 T7405 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2501973 T7433 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 2501973 T7433 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2501973 T7433 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2501974 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2501975 T7430 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "collection":"control_collection",
[junit4] 2> "base_url":"https://127.0.0.1:45925",
[junit4] 2> "node_name":"127.0.0.1:45925_",
[junit4] 2> "shard":null,
[junit4] 2> "numShards":"1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "operation":"state",
[junit4] 2> "core":"collection1"}
[junit4] 2> 2501976 T7430 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 2501976 T7430 oasc.Overseer$ClusterStateUpdater.createCollection state version control_collection 1
[junit4] 2> 2501976 T7430 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2501977 T7434 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> 2502974 T7433 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2502974 T7433 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 2502975 T7433 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2502975 T7433 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2502976 T7433 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2502976 T7433 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/collection1/'
[junit4] 2> 2502977 T7433 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 2502977 T7433 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 2502977 T7433 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 2503001 T7433 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 2503023 T7433 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2503024 T7433 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 2503029 T7433 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2503206 T7433 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2503210 T7433 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2503212 T7433 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2503219 T7433 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2503222 T7433 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2503224 T7433 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2503224 T7433 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2503224 T7433 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2503225 T7433 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2503225 T7433 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2503225 T7433 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2503226 T7433 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 2503226 T7433 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2503226 T7433 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/collection1/data/
[junit4] 2> 2503226 T7433 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1e5c20b
[junit4] 2> 2503227 T7433 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/collection1/data
[junit4] 2> 2503227 T7433 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/collection1/data/index/
[junit4] 2> 2503227 T7433 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2503227 T7433 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-002/collection1/data/index
[junit4] 2> 2503228 T7433 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=14, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4755246674331137]
[junit4] 2> 2503228 T7433 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1f85ef9)),segFN=segments_1,generation=1}
[junit4] 2> 2503228 T7433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2503230 T7433 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2503230 T7433 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2503231 T7433 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2503231 T7433 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2503231 T7433 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2503231 T7433 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2503231 T7433 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2503232 T7433 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2503232 T7433 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2503232 T7433 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2503232 T7433 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2503233 T7433 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2503233 T7433 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2503233 T7433 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2503233 T7433 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2503234 T7433 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2503234 T7433 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2503234 T7433 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2503234 T7433 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2503235 T7433 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2503237 T7433 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2503238 T7433 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2503238 T7433 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2503239 T7433 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2503241 T7433 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2503241 T7433 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2503242 T7433 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 2503242 T7433 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1f85ef9)),segFN=segments_1,generation=1}
[junit4] 2> 2503242 T7433 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2503242 T7433 oass.SolrIndexSearcher.<init> Opening Searcher@1e70239[collection1] main
[junit4] 2> 2503243 T7433 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2503243 T7433 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2503243 T7433 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2503244 T7433 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2503244 T7433 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2503244 T7433 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2503245 T7433 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2503245 T7433 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2503245 T7433 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json
[junit4] 2> 2503247 T7433 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json
[junit4] 2> 2503247 T7433 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2503247 T7433 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2503249 T7435 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e70239[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2503249 T7433 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2503250 T7438 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:45925 collection:control_collection shard:shard1
[junit4] 2> 2503250 T7405 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 2503251 T7405 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2503251 T7438 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 2503253 T7405 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2503254 T7438 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2503254 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2503255 T7440 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12b27f4 name:ZooKeeperConnection Watcher:127.0.0.1:42482/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2503255 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2503256 T7405 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2503256 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2503256 T7438 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2503257 T7438 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 2503256 T7405 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C1393 name=collection1 org.apache.solr.core.SolrCore@13f2761 url=https://127.0.0.1:45925/collection1 node=127.0.0.1:45925_ C1393_STATE=coll:control_collection core:collection1 props:{base_url=https://127.0.0.1:45925, node_name=127.0.0.1:45925_, state=down, core=collection1}
[junit4] 2> 2503257 T7438 C1393 P45925 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:45925/collection1/
[junit4] 2> 2503257 T7438 C1393 P45925 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2503258 T7438 C1393 P45925 oasc.SyncStrategy.syncToMe https://127.0.0.1:45925/collection1/ has no replicas
[junit4] 2> 2503258 T7438 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:45925/collection1/ shard1
[junit4] 2> 2503258 T7438 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 2503259 T7405 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 2503260 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2503362 T7434 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> 2503365 T7441 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> 2503411 T7438 oasc.ZkController.register We are https://127.0.0.1:45925/collection1/ and leader is https://127.0.0.1:45925/collection1/
[junit4] 2> 2503411 T7438 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:45925
[junit4] 2> 2503412 T7438 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2503412 T7438 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 2503412 T7438 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2503414 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2503415 T7430 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "collection":"control_collection",
[junit4] 2> "base_url":"https://127.0.0.1:45925",
[junit4] 2> "node_name":"127.0.0.1:45925_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "numShards":"2",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "core":"collection1"}
[junit4] 2> 2503527 T7441 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> 2503527 T7434 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> 2503597 T7405 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 2503597 T7405 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2503600 T7405 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 2503601 T7405 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:52836
[junit4] 2> 2503603 T7405 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2503604 T7405 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2503604 T7405 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003
[junit4] 2> 2503605 T7405 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/'
[junit4] 2> 2503621 T7405 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/solr.xml
[junit4] 2> 2503654 T7405 oasc.CoreContainer.<init> New CoreContainer 14465796
[junit4] 2> 2503655 T7405 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/]
[junit4] 2> 2503656 T7405 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2503656 T7405 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2503657 T7405 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2503657 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2503658 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
[junit4] 2> 2503658 T7405 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2503658 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2503659 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2503659 T7405 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2503659 T7405 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2503661 T7405 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 2503662 T7405 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2503663 T7405 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2503663 T7405 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2503664 T7405 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42482/solr
[junit4] 2> 2503664 T7405 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2503664 T7405 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2503665 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2503666 T7452 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d1e name:ZooKeeperConnection Watcher:127.0.0.1:42482 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2503666 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2503667 T7405 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2503669 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2503669 T7454 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@107f98f name:ZooKeeperConnection Watcher:127.0.0.1:42482/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2503669 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2503673 T7405 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2504675 T7405 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52836_
[junit4] 2> 2504677 T7405 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52836_
[junit4] 2> 2504678 T7405 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 2504683 T7456 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2504683 T7456 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2504683 T7456 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2504683 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2504685 T7430 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"https://127.0.0.1:52836",
[junit4] 2> "node_name":"127.0.0.1:52836_",
[junit4] 2> "shard":null,
[junit4] 2> "numShards":"2",
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "operation":"state",
[junit4] 2> "core":"collection1"}
[junit4] 2> 2504685 T7430 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 2504686 T7430 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 1
[junit4] 2> 2504686 T7430 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2504788 T7434 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> 2504788 T7455 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> 2504788 T7441 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> 2505684 T7456 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2505684 T7456 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2505685 T7456 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2505685 T7456 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2505685 T7456 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2505686 T7456 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/collection1/'
[junit4] 2> 2505686 T7456 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 2505687 T7456 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 2505687 T7456 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 2505718 T7456 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 2505750 T7456 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2505751 T7456 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 2505758 T7456 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2505958 T7456 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2505963 T7456 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2505965 T7456 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2505973 T7456 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2505975 T7456 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2505978 T7456 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2505979 T7456 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2505979 T7456 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2505979 T7456 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2505980 T7456 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2505980 T7456 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2505981 T7456 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2505981 T7456 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2505981 T7456 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/collection1/data/
[junit4] 2> 2505981 T7456 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1e5c20b
[junit4] 2> 2505982 T7456 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/collection1/data
[junit4] 2> 2505982 T7456 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/collection1/data/index/
[junit4] 2> 2505983 T7456 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2505983 T7456 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-003/collection1/data/index
[junit4] 2> 2505983 T7456 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=14, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4755246674331137]
[junit4] 2> 2505984 T7456 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1e2e469)),segFN=segments_1,generation=1}
[junit4] 2> 2505984 T7456 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2505987 T7456 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2505988 T7456 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2505988 T7456 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2505988 T7456 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2505988 T7456 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2505989 T7456 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2505989 T7456 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2505989 T7456 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2505990 T7456 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2505990 T7456 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2505990 T7456 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2505991 T7456 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2505991 T7456 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2505991 T7456 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2505991 T7456 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2505992 T7456 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2505992 T7456 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2505992 T7456 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2505993 T7456 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2505993 T7456 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2505995 T7456 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2505996 T7456 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2505997 T7456 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2505998 T7456 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2505999 T7456 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2506000 T7456 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2506000 T7456 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 2506001 T7456 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1e2e469)),segFN=segments_1,generation=1}
[junit4] 2> 2506001 T7456 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2506001 T7456 oass.SolrIndexSearcher.<init> Opening Searcher@12740df[collection1] main
[junit4] 2> 2506001 T7456 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2506002 T7456 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2506002 T7456 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2506002 T7456 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2506002 T7456 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2506003 T7456 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2506003 T7456 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 2506003 T7456 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2506004 T7456 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 2506004 T7456 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2506006 T7457 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@12740df[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2506008 T7456 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2506008 T7460 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:52836 collection:collection1 shard:shard2
[junit4] 2> 2506008 T7405 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 2506009 T7405 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2506012 T7460 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2506015 T7460 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 2506017 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2506017 T7460 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2506017 T7460 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1394 name=collection1 org.apache.solr.core.SolrCore@1469e55 url=https://127.0.0.1:52836/collection1 node=127.0.0.1:52836_ C1394_STATE=coll:collection1 core:collection1 props:{base_url=https://127.0.0.1:52836, node_name=127.0.0.1:52836_, state=down, core=collection1}
[junit4] 2> 2506017 T7460 C1394 P52836 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:52836/collection1/
[junit4] 2> 2506018 T7460 C1394 P52836 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2506018 T7460 C1394 P52836 oasc.SyncStrategy.syncToMe https://127.0.0.1:52836/collection1/ has no replicas
[junit4] 2> 2506018 T7460 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:52836/collection1/ shard2
[junit4] 2> 2506018 T7460 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2506021 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2506123 T7455 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> 2506124 T7441 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> 2506124 T7434 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> 2506172 T7460 oasc.ZkController.register We are https://127.0.0.1:52836/collection1/ and leader is https://127.0.0.1:52836/collection1/
[junit4] 2> 2506172 T7460 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:52836
[junit4] 2> 2506172 T7460 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2506173 T7460 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 2506173 T7460 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2506174 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2506176 T7430 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"https://127.0.0.1:52836",
[junit4] 2> "node_name":"127.0.0.1:52836_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "numShards":"2",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "core":"collection1"}
[junit4] 2> 2506242 T7405 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 2506242 T7405 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2506245 T7405 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 2506245 T7405 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:58119
[junit4] 2> 2506247 T7405 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2506248 T7405 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2506248 T7405 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004
[junit4] 2> 2506248 T7405 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/'
[junit4] 2> 2506260 T7405 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/solr.xml
[junit4] 2> 2506278 T7434 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> 2506278 T7441 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> 2506278 T7455 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> 2506285 T7405 oasc.CoreContainer.<init> New CoreContainer 1815663
[junit4] 2> 2506286 T7405 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/]
[junit4] 2> 2506286 T7405 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2506287 T7405 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2506287 T7405 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2506287 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2506287 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
[junit4] 2> 2506288 T7405 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2506288 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2506288 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2506289 T7405 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2506289 T7405 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2506290 T7405 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 2506291 T7405 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2506291 T7405 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2506292 T7405 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2506292 T7405 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42482/solr
[junit4] 2> 2506292 T7405 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2506292 T7405 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2506293 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2506294 T7471 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c32115 name:ZooKeeperConnection Watcher:127.0.0.1:42482 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2506294 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2506295 T7405 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2506296 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2506296 T7473 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ac1f57 name:ZooKeeperConnection Watcher:127.0.0.1:42482/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2506296 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2506300 T7405 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2507302 T7405 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58119_
[junit4] 2> 2507303 T7405 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58119_
[junit4] 2> 2507306 T7405 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 2507310 T7475 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2507310 T7475 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2507311 T7475 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2507311 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2507313 T7430 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"https://127.0.0.1:58119",
[junit4] 2> "node_name":"127.0.0.1:58119_",
[junit4] 2> "shard":null,
[junit4] 2> "numShards":"2",
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "operation":"state",
[junit4] 2> "core":"collection1"}
[junit4] 2> 2507313 T7430 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 2507313 T7430 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2507415 T7455 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> 2507415 T7474 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> 2507415 T7434 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> 2507415 T7441 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> 2508311 T7475 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2508311 T7475 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2508312 T7475 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2508312 T7475 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2508313 T7475 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2508313 T7475 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/collection1/'
[junit4] 2> 2508314 T7475 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 2508314 T7475 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 2508314 T7475 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 2508338 T7475 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 2508374 T7475 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2508375 T7475 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 2508383 T7475 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2508629 T7475 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2508635 T7475 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2508638 T7475 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2508646 T7475 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2508648 T7475 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2508650 T7475 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2508650 T7475 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2508651 T7475 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2508651 T7475 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2508651 T7475 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2508652 T7475 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2508652 T7475 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2508652 T7475 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2508652 T7475 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/collection1/data/
[junit4] 2> 2508652 T7475 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1e5c20b
[junit4] 2> 2508653 T7475 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/collection1/data
[junit4] 2> 2508654 T7475 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/collection1/data/index/
[junit4] 2> 2508654 T7475 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2508654 T7475 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-004/collection1/data/index
[junit4] 2> 2508654 T7475 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=14, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4755246674331137]
[junit4] 2> 2508655 T7475 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1ac195)),segFN=segments_1,generation=1}
[junit4] 2> 2508655 T7475 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2508657 T7475 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2508658 T7475 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2508658 T7475 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2508658 T7475 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2508658 T7475 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2508658 T7475 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2508659 T7475 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2508659 T7475 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2508659 T7475 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2508659 T7475 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2508660 T7475 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2508660 T7475 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2508660 T7475 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2508661 T7475 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2508661 T7475 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2508661 T7475 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2508661 T7475 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2508662 T7475 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2508662 T7475 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2508662 T7475 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2508664 T7475 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2508665 T7475 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2508666 T7475 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2508667 T7475 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2508669 T7475 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2508669 T7475 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2508669 T7475 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 2508670 T7475 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1ac195)),segFN=segments_1,generation=1}
[junit4] 2> 2508670 T7475 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2508670 T7475 oass.SolrIndexSearcher.<init> Opening Searcher@1814cd1[collection1] main
[junit4] 2> 2508670 T7475 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2508671 T7475 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2508671 T7475 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2508672 T7475 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2508672 T7475 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2508672 T7475 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2508673 T7475 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 2508673 T7475 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2508673 T7475 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 2508673 T7475 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2508675 T7476 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1814cd1[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2508677 T7475 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2508677 T7479 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:58119 collection:collection1 shard:shard1
[junit4] 2> 2508677 T7405 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 2508678 T7405 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2508678 T7479 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2508681 T7479 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2508682 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2508682 T7479 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2508682 T7479 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1395 name=collection1 org.apache.solr.core.SolrCore@ed868 url=https://127.0.0.1:58119/collection1 node=127.0.0.1:58119_ C1395_STATE=coll:collection1 core:collection1 props:{base_url=https://127.0.0.1:58119, node_name=127.0.0.1:58119_, state=down, core=collection1}
[junit4] 2> 2508682 T7479 C1395 P58119 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:58119/collection1/
[junit4] 2> 2508683 T7479 C1395 P58119 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2508683 T7479 C1395 P58119 oasc.SyncStrategy.syncToMe https://127.0.0.1:58119/collection1/ has no replicas
[junit4] 2> 2508683 T7479 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:58119/collection1/ shard1
[junit4] 2> 2508683 T7479 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2508685 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2508788 T7474 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> 2508788 T7434 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> 2508788 T7455 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> 2508788 T7441 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> 2508836 T7479 oasc.ZkController.register We are https://127.0.0.1:58119/collection1/ and leader is https://127.0.0.1:58119/collection1/
[junit4] 2> 2508836 T7479 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:58119
[junit4] 2> 2508837 T7479 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2508837 T7479 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 2508837 T7479 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2508838 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2508840 T7430 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"https://127.0.0.1:58119",
[junit4] 2> "node_name":"127.0.0.1:58119_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "numShards":"2",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "core":"collection1"}
[junit4] 2> 2508908 T7405 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 2508909 T7405 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2508911 T7405 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 2508912 T7405 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:38814
[junit4] 2> 2508914 T7405 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2508914 T7405 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2508915 T7405 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-005
[junit4] 2> 2508915 T7405 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-005/'
[junit4] 2> 2508925 T7405 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-005/solr.xml
[junit4] 2> 2508942 T7434 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> 2508942 T7441 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> 2508942 T7474 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> 2508942 T7455 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> 2508948 T7405 oasc.CoreContainer.<init> New CoreContainer 11576069
[junit4] 2> 2508949 T7405 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.MultiThreadedOCPTest-CE6D0732FFA7EB0D-001/tempDir-005/]
[junit4] 2> 2508949 T7405 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2508950 T7405 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2508950 T7405 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2508950 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2508950 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
[junit4] 2> 2508951 T7405 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2508951 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2508951 T7405 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2508952 T7405 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2508952 T7405 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2508953 T7405 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 2508954 T7405 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2508954 T7405 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2508955 T7405 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2508955 T7405 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42482/solr
[junit4] 2> 2508955 T7405 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2508955 T7405 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
[junit4] 2> 2508956 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2508957 T7490 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47024a name:ZooKeeperConnection Watcher:127.0.0.1:42482 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2508957 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2508958 T7405 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
[junit4] 2> 2508959 T7405 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2508960 T7492 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bb475c name:ZooKeeperConnection Watcher:127.0.0.1:42482/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2508960 T7405 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2508963 T7405 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2509965 T7405 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38814_
[junit4] 2> 2509966 T7405 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38814_
[junit4] 2> 2509969 T7405 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 2509972 T7494 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2509972 T7494 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2509973 T7494 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2509973 T7434 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 2509975 T7430 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"https://127.0.0.1:38814",
[junit4] 2> "node_name":"127.0.0.1:38814_",
[junit4] 2> "shard":null,
[junit4] 2> "numShards":"2",
[junit4] 2> "roles":null,
[
[...truncated too long message...]
retryOperation(ZkCmdExecutor.java:61)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:379)
[junit4] 2> at org.apache.solr.cloud.DistributedMap.createData(DistributedMap.java:112)
[junit4] 2> at org.apache.solr.cloud.DistributedMap.put(DistributedMap.java:125)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor$Runner.run(OverseerCollectionProcessor.java:2864)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2682071 T7594 oasc.OverseerCollectionProcessor$Runner.resetTaskWithException WARN Resetting task: /overseer/collection-queue-work/qn-0000000010, requestid: 2000, collectionName: collection1
[junit4] 2> 2682072 T7594 oasc.SolrException.log ERROR :org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/collection-map-running/mn-2000
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:246)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:243)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:243)
[junit4] 2> at org.apache.solr.cloud.DistributedMap.remove(DistributedMap.java:167)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor$Runner.resetTaskWithException(OverseerCollectionProcessor.java:2924)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor$Runner.run(OverseerCollectionProcessor.java:2892)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 180541 T7404 ccr.ThreadLeakControl.tryToInterruptAll All leaked threads terminated.
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=DefaultSimilarity, locale=ar_KW, timezone=America/Cayman
[junit4] 2> NOTE: Linux 3.13.0-39-generic i386/Oracle Corporation 1.7.0_67 (32-bit)/cpus=8,threads=1,free=247268024,total=494141440
[junit4] 2> NOTE: All tests run in this JVM: [TestGroupingSearch, TestCursorMarkWithoutUniqueKey, TestBM25SimilarityFactory, CacheHeaderTest, RequestHandlersTest, TestPerFieldSimilarity, TestExceedMaxTermLength, MigrateRouteKeyTest, TestSchemaResource, UUIDFieldTest, TestRandomMergePolicy, TestClassNameShortening, TestIndexingPerformance, TestSolrQueryParserResource, TestRecovery, UpdateRequestProcessorFactoryTest, LeaderElectionIntegrationTest, SolrPluginUtilsTest, DistributedFacetPivotSmallAdvancedTest, CoreAdminCreateDiscoverTest, SoftAutoCommitTest, TestXIncludeConfig, SolrIndexConfigTest, TestFunctionQuery, AutoCommitTest, TestValueSourceCache, RAMDirectoryFactoryTest, QueryResultKeyTest, TermVectorComponentTest, CollectionsAPIAsyncDistributedZkTest, DistributedQueryComponentOptimizationTest, LukeRequestHandlerTest, BadCopyFieldTest, SimplePostToolTest, PrimUtilsTest, TestFileDictionaryLookup, CurrencyFieldXmlFileTest, TestSolrQueryParserDefaultOperatorResource, IndexSchemaRuntimeFieldTest, TestCSVResponseWriter, TestPseudoReturnFields, TestJoin, QueryParsingTest, TestReversedWildcardFilterFactory, DirectUpdateHandlerOptimizeTest, CircularListTest, TestExtendedDismaxParser, TestTolerantSearch, TestSolrXml, SortByFunctionTest, SynonymTokenizerTest, TestMaxScoreQueryParser, ChangedSchemaMergeTest, TestPivotHelperCode, TestFiltering, TestWriterPerf, TestSearcherReuse, PolyFieldTest, CopyFieldTest, TestReloadAndDeleteDocs, DistributedQueryElevationComponentTest, TestMultiCoreConfBootstrap, ShardRoutingCustomTest, TestStandardQParsers, AnalysisAfterCoreReloadTest, DistributedFacetPivotSmallTest, ExitableDirectoryReaderTest, TestDynamicFieldResource, ResourceLoaderTest, HdfsBasicDistributedZk2Test, TestHighlightDedupGrouping, TestJmxMonitoredMap, TestNonDefinedSimilarityFactory, TestSortingResponseWriter, SearchHandlerTest, EnumFieldTest, TestManagedSchema, TestLeaderElectionZkExpiry, TestSweetSpotSimilarityFactory, TestManagedResource, ClusterStateTest, VMParamsZkACLAndCredentialsProvidersTest, BinaryUpdateRequestHandlerTest, HdfsWriteToMultipleCollectionsTest, SolrCoreTest, TestManagedSchemaFieldResource, HdfsCollectionsAPIDistributedZkTest, TestShortCircuitedRequests, ScriptEngineTest, UniqFieldsUpdateProcessorFactoryTest, StatsComponentTest, TestUpdate, TestIBSimilarityFactory, LeaderFailoverAfterPartitionTest, TestPostingsSolrHighlighter, SolrTestCaseJ4Test, LegacyHTMLStripCharFilterTest, TestUtils, ShardSplitTest, TestReplicaProperties, DistanceFunctionTest, SOLR749Test, TestRealTimeGet, TestCollapseQParserPlugin, TestStressLucene, HdfsUnloadDistributedZkTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, SyncSliceTest, OpenCloseCoreStressTest, OverseerTest, ShardRoutingTest, BasicZkTest, FullSolrCloudDistribCmdsTest, TestRandomFaceting, ZkSolrClientTest, TestZkChroot, ZkCLITest, TestDistributedSearch, TestDistributedGrouping, TermVectorComponentDistributedTest, HardAutoCommitTest, TestRangeQuery, TestCoreContainer, SpellCheckComponentTest, SolrCmdDistributorTest, QueryElevationComponentTest, BadIndexSchemaTest, TestSort, DirectUpdateHandlerTest, OverseerCollectionProcessorTest, HighlighterTest, SpellCheckCollatorTest, SuggesterFSTTest, SolrRequestParserTest, TestFoldingMultitermQuery, DocValuesTest, SuggesterTest, SpatialFilterTest, NoCacheHeaderTest, QueryEqualityTest, TestRemoteStreaming, TestQueryTypes, TestOmitPositions, TermsComponentTest, PathHierarchyTokenizerFactoryTest, FieldAnalysisRequestHandlerTest, TestArbitraryIndexDir, LoggingHandlerTest, TestCollationField, MBeansHandlerTest, TestAnalyzedSuggestions, TestPHPSerializedResponseWriter, TestComponentsName, TestBinaryResponseWriter, TestQuerySenderListener, TestQuerySenderNoQuery, BadComponentTest, TestSolrDeletionPolicy2, MultiTermTest, TestBinaryField, TestLMJelinekMercerSimilarityFactory, TimeZoneUtilsTest, URLClassifyProcessorTest, DateMathParserTest, TestSystemIdResolver, DateFieldTest, AliasIntegrationTest, AssignTest, CloudExitableDirectoryReaderTest, DeleteInactiveReplicaTest, DistribDocExpirationUpdateProcessorTest, MultiThreadedOCPTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=MultiThreadedOCPTest -Dtests.seed=CE6D0732FFA7EB0D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_KW -Dtests.timezone=America/Cayman -Dtests.asserts=false -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J1 | MultiThreadedOCPTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.MultiThreadedOCPTest:
[junit4] > 1) Thread[id=7594, name=OverseerThreadFactory-4096-thread-5, state=TIMED_WAITING, group=Overseer collection creation process.]
[junit4] > at java.lang.Thread.sleep(Native Method)
[junit4] > at org.apache.solr.cloud.OverseerCollectionProcessor.waitForCoreNodeName(OverseerCollectionProcessor.java:1847)
[junit4] > at org.apache.solr.cloud.OverseerCollectionProcessor.splitShard(OverseerCollectionProcessor.java:1729)
[junit4] > at org.apache.solr.cloud.OverseerCollectionProcessor.processMessage(OverseerCollectionProcessor.java:615)
[junit4] > at org.apache.solr.cloud.OverseerCollectionProcessor$Runner.run(OverseerCollectionProcessor.java:2856)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > at __randomizedtesting.SeedInfo.seed([CE6D0732FFA7EB0D]:0)
[junit4] Completed on J1 in 180.57s, 1 test, 1 error <<< FAILURES!
[...truncated 242 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:525: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:473: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/build.xml:61: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/extra-targets.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/common-build.xml:502: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/lucene/common-build.xml:1359: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-5.x-Linux/lucene/common-build.xml:966: There were test failures: 444 suites, 1818 tests, 1 suite-level error, 44 ignored (21 assumptions)
Total time: 102 minutes 13 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/jdk1.7.0_67 -server -XX:+UseParallelGC (asserts: false)
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any