You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/11/14 03:26:11 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java7 - Build # 1759 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1759/
2 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.TestDistribDocBasedVersion
Error Message:
Captured an uncaught exception in thread: Thread[id=4368, name=Lucene Merge Thread #0, state=RUNNABLE, group=TGRP-TestDistribDocBasedVersion]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=4368, name=Lucene Merge Thread #0, state=RUNNABLE, group=TGRP-TestDistribDocBasedVersion]
Caused by: org.apache.lucene.index.MergePolicy$MergeException: java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([5C465C9D1FE2E116]:0)
at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:545)
at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:518)
Caused by: java.lang.AssertionError
at org.apache.lucene.index.IndexWriter._mergeInit(IndexWriter.java:3808)
at org.apache.lucene.index.IndexWriter.mergeInit(IndexWriter.java:3792)
at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3645)
at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.TestDistribDocBasedVersion
Error Message:
Captured an uncaught exception in thread: Thread[id=4369, name=Lucene Merge Thread #0, state=RUNNABLE, group=TGRP-TestDistribDocBasedVersion]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=4369, name=Lucene Merge Thread #0, state=RUNNABLE, group=TGRP-TestDistribDocBasedVersion]
Caused by: org.apache.lucene.index.MergePolicy$MergeException: java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([5C465C9D1FE2E116]:0)
at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:545)
at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:518)
Caused by: java.lang.AssertionError
at org.apache.lucene.index.IndexWriter._mergeInit(IndexWriter.java:3808)
at org.apache.lucene.index.IndexWriter.mergeInit(IndexWriter.java:3792)
at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3645)
at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
Build Log:
[...truncated 10443 lines...]
[junit4] Suite: org.apache.solr.cloud.TestDistribDocBasedVersion
[junit4] 2> 1843095 T4248 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /ba/ji
[junit4] 2> 1843100 T4248 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./solrtest-TestDistribDocBasedVersion-1384395521816
[junit4] 2> 1843102 T4248 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1843103 T4249 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1843203 T4248 oasc.ZkTestServer.run start zk server on port:55650
[junit4] 2> 1843204 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1843209 T4255 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fe4345d name:ZooKeeperConnection Watcher:127.0.0.1:55650 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1843209 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1843210 T4248 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1843222 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1843224 T4257 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e2f911e name:ZooKeeperConnection Watcher:127.0.0.1:55650/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1843224 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1843225 T4248 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1843235 T4248 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1843238 T4248 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1843241 T4248 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1843250 T4248 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-externalversionconstraint.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1843251 T4248 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1843267 T4248 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 1843268 T4248 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1843372 T4248 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1843373 T4248 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1843384 T4248 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1843385 T4248 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1843388 T4248 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1843389 T4248 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1843393 T4248 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1843394 T4248 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1843398 T4248 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1843398 T4248 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1843402 T4248 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1843402 T4248 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1843405 T4248 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1843406 T4248 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1843409 T4248 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1843410 T4248 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1843413 T4248 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1843414 T4248 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1843706 T4248 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1843711 T4248 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:55654
[junit4] 2> 1843712 T4248 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1843712 T4248 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1843713 T4248 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-controljetty-1384395522139
[junit4] 2> 1843713 T4248 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-controljetty-1384395522139/'
[junit4] 2> 1843757 T4248 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-controljetty-1384395522139/solr.xml
[junit4] 2> 1843896 T4248 oasc.CoreContainer.<init> New CoreContainer 1981290287
[junit4] 2> 1843897 T4248 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-controljetty-1384395522139/]
[junit4] 2> 1843899 T4248 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1843900 T4248 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1843900 T4248 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1843901 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1843901 T4248 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1843901 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1843902 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1843902 T4248 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1843903 T4248 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1843910 T4248 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1843910 T4248 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1843911 T4248 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55650/solr
[junit4] 2> 1843911 T4248 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1843912 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1843916 T4268 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55d3c224 name:ZooKeeperConnection Watcher:127.0.0.1:55650 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1843916 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1843920 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1843922 T4270 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ed463a7 name:ZooKeeperConnection Watcher:127.0.0.1:55650/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1843923 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1843930 T4248 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1843934 T4248 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1843944 T4248 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1843946 T4248 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55654_ba%2Fji
[junit4] 2> 1843948 T4248 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55654_ba%2Fji
[junit4] 2> 1843958 T4248 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1843970 T4248 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1843973 T4248 oasc.Overseer.start Overseer (id=90727744918257667-127.0.0.1:55654_ba%2Fji-n_0000000000) starting
[junit4] 2> 1843987 T4248 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1843991 T4272 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1843992 T4248 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1843994 T4248 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1843996 T4248 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1843998 T4271 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1844005 T4273 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1844005 T4273 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1844006 T4273 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1845502 T4271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1845503 T4271 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55654/ba/ji",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55654_ba%2Fji",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1845504 T4271 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1845504 T4271 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1845522 T4270 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> 1846008 T4273 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1846008 T4273 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-controljetty-1384395522139/collection1
[junit4] 2> 1846008 T4273 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1846009 T4273 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1846010 T4273 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1846011 T4273 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-controljetty-1384395522139/collection1/'
[junit4] 2> 1846013 T4273 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-controljetty-1384395522139/collection1/lib/classes/' to classloader
[junit4] 2> 1846014 T4273 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-controljetty-1384395522139/collection1/lib/README' to classloader
[junit4] 2> 1846079 T4273 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 1846144 T4273 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1846246 T4273 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1846257 T4273 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1846843 T4273 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1846847 T4273 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1846849 T4273 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1846855 T4273 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1846878 T4273 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4] 2> 1846878 T4273 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-controljetty-1384395522139/collection1/, dataDir=./org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/control/data/
[junit4] 2> 1846879 T4273 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6237ea01
[junit4] 2> 1846880 T4273 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/control/data
[junit4] 2> 1846881 T4273 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/control/data/index/
[junit4] 2> 1846882 T4273 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1846883 T4273 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/control/data/index
[junit4] 2> 1846884 T4273 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=16.9248046875, floorSegmentMB=1.0458984375, forceMergeDeletesPctAllowed=14.621001701159022, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1846891 T4273 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/control/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@24a3c1b8; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 1846892 T4273 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1846895 T4273 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-constraint" (default)
[junit4] 2> 1846980 T4273 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-constraint" (default)
[junit4] 2> 1846981 T4273 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-float"
[junit4] 2> 1846981 T4273 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-float"
[junit4] 2> 1846981 T4273 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-failhard"
[junit4] 2> 1846982 T4273 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-failhard"
[junit4] 2> 1846982 T4273 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1846982 T4273 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1846983 T4273 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1846984 T4273 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1846984 T4273 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1847000 T4273 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1847008 T4273 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1847008 T4273 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1847010 T4273 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@48e07429
[junit4] 2> 1847011 T4273 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/control/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@24a3c1b8; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 1847012 T4273 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1847012 T4273 oass.SolrIndexSearcher.<init> Opening Searcher@297aabef main
[junit4] 2> 1847013 T4274 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@297aabef main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1847014 T4273 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1847014 T4273 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55654/ba/ji collection:control_collection shard:shard1
[junit4] 2> 1847021 T4273 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1847109 T4273 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1847166 T4273 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1847166 T4273 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1847166 T4273 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55654/ba/ji/collection1/
[junit4] 2> 1847167 T4273 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1847167 T4273 oasc.SyncStrategy.syncToMe http://127.0.0.1:55654/ba/ji/collection1/ has no replicas
[junit4] 2> 1847167 T4273 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55654/ba/ji/collection1/ shard1
[junit4] 2> 1847168 T4273 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1848598 T4271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1848619 T4270 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> 1848664 T4273 oasc.ZkController.register We are http://127.0.0.1:55654/ba/ji/collection1/ and leader is http://127.0.0.1:55654/ba/ji/collection1/
[junit4] 2> 1848664 T4273 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55654/ba/ji
[junit4] 2> 1848664 T4273 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1848664 T4273 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1848665 T4273 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1848667 T4273 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1848668 T4248 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1848669 T4248 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1848671 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1848673 T4277 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1918d526 name:ZooKeeperConnection Watcher:127.0.0.1:55650/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1848674 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1848675 T4248 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1848677 T4248 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1848958 T4248 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1848962 T4248 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:55661
[junit4] 2> 1848963 T4248 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1848963 T4248 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1848964 T4248 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty1-1384395527393
[junit4] 2> 1848964 T4248 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.TestDistribDocBasedVersion-jetty1-1384395527393/'
[junit4] 2> 1849006 T4248 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty1-1384395527393/solr.xml
[junit4] 2> 1849099 T4248 oasc.CoreContainer.<init> New CoreContainer 313524230
[junit4] 2> 1849100 T4248 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty1-1384395527393/]
[junit4] 2> 1849102 T4248 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1849102 T4248 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1849103 T4248 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1849103 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1849104 T4248 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1849104 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1849105 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1849105 T4248 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1849106 T4248 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1849112 T4248 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1849113 T4248 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1849114 T4248 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55650/solr
[junit4] 2> 1849114 T4248 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1849115 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1849118 T4288 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@699cddf6 name:ZooKeeperConnection Watcher:127.0.0.1:55650 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1849119 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1849137 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1849140 T4290 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f85619f name:ZooKeeperConnection Watcher:127.0.0.1:55650/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1849140 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1849145 T4248 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1850124 T4271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1850125 T4271 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:55654/ba/ji",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55654_ba%2Fji",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1850130 T4277 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> 1850130 T4270 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> 1850130 T4290 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> 1850148 T4248 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55661_ba%2Fji
[junit4] 2> 1850150 T4248 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55661_ba%2Fji
[junit4] 2> 1850158 T4277 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1850158 T4290 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1850158 T4270 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1850167 T4291 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1850167 T4291 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1850169 T4291 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1851648 T4271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1851649 T4271 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55661/ba/ji",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55661_ba%2Fji",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1851650 T4271 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 1851650 T4271 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1851667 T4277 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> 1851667 T4270 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> 1851667 T4290 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> 1852171 T4291 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1852171 T4291 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty1-1384395527393/collection1
[junit4] 2> 1852171 T4291 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1852172 T4291 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1852173 T4291 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1852174 T4291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.TestDistribDocBasedVersion-jetty1-1384395527393/collection1/'
[junit4] 2> 1852175 T4291 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-jetty1-1384395527393/collection1/lib/classes/' to classloader
[junit4] 2> 1852176 T4291 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-jetty1-1384395527393/collection1/lib/README' to classloader
[junit4] 2> 1852273 T4291 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 1852338 T4291 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1852440 T4291 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1852451 T4291 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1853018 T4291 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1853021 T4291 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1853023 T4291 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1853027 T4291 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1853047 T4291 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4] 2> 1853048 T4291 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty1-1384395527393/collection1/, dataDir=./org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty1/
[junit4] 2> 1853048 T4291 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6237ea01
[junit4] 2> 1853049 T4291 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty1
[junit4] 2> 1853050 T4291 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty1/index/
[junit4] 2> 1853051 T4291 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1853052 T4291 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty1/index
[junit4] 2> 1853053 T4291 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=16.9248046875, floorSegmentMB=1.0458984375, forceMergeDeletesPctAllowed=14.621001701159022, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1853084 T4291 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty1/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@59b3953c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 1853084 T4291 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1853088 T4291 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-constraint" (default)
[junit4] 2> 1853089 T4291 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-constraint" (default)
[junit4] 2> 1853089 T4291 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-float"
[junit4] 2> 1853090 T4291 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-float"
[junit4] 2> 1853090 T4291 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-failhard"
[junit4] 2> 1853090 T4291 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-failhard"
[junit4] 2> 1853091 T4291 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1853091 T4291 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1853092 T4291 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1853092 T4291 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1853093 T4291 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1853110 T4291 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1853118 T4291 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1853118 T4291 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1853120 T4291 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@1ba0b8e5
[junit4] 2> 1853122 T4291 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty1/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@59b3953c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 1853122 T4291 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1853123 T4291 oass.SolrIndexSearcher.<init> Opening Searcher@4f42461f main
[junit4] 2> 1853124 T4292 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4f42461f main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1853125 T4291 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1853126 T4291 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55661/ba/ji collection:collection1 shard:shard1
[junit4] 2> 1853133 T4291 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1853152 T4291 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1853164 T4291 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1853164 T4291 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1853164 T4291 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55661/ba/ji/collection1/
[junit4] 2> 1853164 T4291 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1853165 T4291 oasc.SyncStrategy.syncToMe http://127.0.0.1:55661/ba/ji/collection1/ has no replicas
[junit4] 2> 1853165 T4291 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55661/ba/ji/collection1/ shard1
[junit4] 2> 1853165 T4291 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1853179 T4271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1853203 T4270 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> 1853203 T4277 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> 1853203 T4290 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> 1853231 T4291 oasc.ZkController.register We are http://127.0.0.1:55661/ba/ji/collection1/ and leader is http://127.0.0.1:55661/ba/ji/collection1/
[junit4] 2> 1853231 T4291 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55661/ba/ji
[junit4] 2> 1853231 T4291 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1853231 T4291 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1853231 T4291 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1853233 T4291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1853234 T4248 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1853235 T4248 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1853517 T4248 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1853520 T4248 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:55665
[junit4] 2> 1853521 T4248 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1853521 T4248 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1853522 T4248 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty2-1384395531951
[junit4] 2> 1853522 T4248 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.TestDistribDocBasedVersion-jetty2-1384395531951/'
[junit4] 2> 1853565 T4248 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty2-1384395531951/solr.xml
[junit4] 2> 1853660 T4248 oasc.CoreContainer.<init> New CoreContainer 2071256929
[junit4] 2> 1853661 T4248 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty2-1384395531951/]
[junit4] 2> 1853663 T4248 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1853663 T4248 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1853664 T4248 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1853664 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1853665 T4248 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1853665 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1853666 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1853666 T4248 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1853667 T4248 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1853673 T4248 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1853674 T4248 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1853675 T4248 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55650/solr
[junit4] 2> 1853675 T4248 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1853676 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1853679 T4304 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17c65490 name:ZooKeeperConnection Watcher:127.0.0.1:55650 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1853680 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1853694 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1853696 T4306 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2c52ac1 name:ZooKeeperConnection Watcher:127.0.0.1:55650/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1853696 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1853701 T4248 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1854704 T4248 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55665_ba%2Fji
[junit4] 2> 1854716 T4248 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55665_ba%2Fji
[junit4] 2> 1854718 T4271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1854720 T4271 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:55661/ba/ji",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55661_ba%2Fji",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1854721 T4306 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1854721 T4290 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1854720 T4277 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1854734 T4277 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> 1854735 T4290 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> 1854735 T4306 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> 1854739 T4307 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1854739 T4307 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1854745 T4307 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1854745 T4270 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1854745 T4270 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> 1856247 T4271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1856248 T4271 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55665/ba/ji",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55665_ba%2Fji",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1856249 T4271 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1856249 T4271 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1856299 T4277 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> 1856299 T4306 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> 1856299 T4290 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> 1856299 T4270 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> 1856747 T4307 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1856747 T4307 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty2-1384395531951/collection1
[junit4] 2> 1856747 T4307 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1856748 T4307 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1856748 T4307 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1856749 T4307 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.TestDistribDocBasedVersion-jetty2-1384395531951/collection1/'
[junit4] 2> 1856751 T4307 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-jetty2-1384395531951/collection1/lib/classes/' to classloader
[junit4] 2> 1856752 T4307 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-jetty2-1384395531951/collection1/lib/README' to classloader
[junit4] 2> 1856818 T4307 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 1856913 T4307 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1857015 T4307 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1857028 T4307 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1857616 T4307 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1857620 T4307 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1857622 T4307 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1857628 T4307 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1857651 T4307 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4] 2> 1857651 T4307 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty2-1384395531951/collection1/, dataDir=./org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty2/
[junit4] 2> 1857652 T4307 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6237ea01
[junit4] 2> 1857653 T4307 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty2
[junit4] 2> 1857654 T4307 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty2/index/
[junit4] 2> 1857655 T4307 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1857657 T4307 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty2/index
[junit4] 2> 1857658 T4307 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=16.9248046875, floorSegmentMB=1.0458984375, forceMergeDeletesPctAllowed=14.621001701159022, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1857666 T4307 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@14f4d712; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 1857667 T4307 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1857671 T4307 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-constraint" (default)
[junit4] 2> 1857672 T4307 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-constraint" (default)
[junit4] 2> 1857672 T4307 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-float"
[junit4] 2> 1857672 T4307 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-float"
[junit4] 2> 1857673 T4307 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-failhard"
[junit4] 2> 1857673 T4307 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-failhard"
[junit4] 2> 1857673 T4307 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1857674 T4307 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1857674 T4307 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1857675 T4307 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1857676 T4307 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1857693 T4307 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1857701 T4307 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1857702 T4307 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1857703 T4307 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@5a1f72c4
[junit4] 2> 1857705 T4307 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@14f4d712; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 1857705 T4307 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1857706 T4307 oass.SolrIndexSearcher.<init> Opening Searcher@334e36f0 main
[junit4] 2> 1857707 T4308 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@334e36f0 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1857709 T4307 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1857709 T4307 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55665/ba/ji collection:collection1 shard:shard2
[junit4] 2> 1857716 T4307 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1857736 T4307 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1857747 T4307 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1857747 T4307 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1857747 T4307 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55665/ba/ji/collection1/
[junit4] 2> 1857747 T4307 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1857748 T4307 oasc.SyncStrategy.syncToMe http://127.0.0.1:55665/ba/ji/collection1/ has no replicas
[junit4] 2> 1857748 T4307 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55665/ba/ji/collection1/ shard2
[junit4] 2> 1857748 T4307 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1857804 T4271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1857820 T4270 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> 1857820 T4290 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> 1857820 T4306 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> 1857820 T4277 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> 1857855 T4307 oasc.ZkController.register We are http://127.0.0.1:55665/ba/ji/collection1/ and leader is http://127.0.0.1:55665/ba/ji/collection1/
[junit4] 2> 1857855 T4307 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55665/ba/ji
[junit4] 2> 1857855 T4307 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1857855 T4307 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1857856 T4307 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1857858 T4307 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1857859 T4248 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1857860 T4248 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1858139 T4248 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1858142 T4248 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:55668
[junit4] 2> 1858143 T4248 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1858144 T4248 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1858144 T4248 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty3-1384395536576
[junit4] 2> 1858145 T4248 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty3-1384395536576/'
[junit4] 2> 1858187 T4248 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty3-1384395536576/solr.xml
[junit4] 2> 1858280 T4248 oasc.CoreContainer.<init> New CoreContainer 619098795
[junit4] 2> 1858281 T4248 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty3-1384395536576/]
[junit4] 2> 1858283 T4248 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1858283 T4248 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1858284 T4248 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1858284 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1858285 T4248 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1858285 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1858286 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1858286 T4248 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1858287 T4248 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1858293 T4248 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1858294 T4248 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1858295 T4248 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55650/solr
[junit4] 2> 1858295 T4248 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1858296 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1858299 T4320 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3bb7509b name:ZooKeeperConnection Watcher:127.0.0.1:55650 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1858300 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1858310 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1858312 T4322 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33d9355c name:ZooKeeperConnection Watcher:127.0.0.1:55650/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1858313 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1858324 T4248 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1859328 T4248 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55668_ba%2Fji
[junit4] 2> 1859332 T4248 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55668_ba%2Fji
[junit4] 2> 1859333 T4271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1859336 T4277 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1859336 T4290 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1859336 T4306 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1859336 T4322 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1859336 T4271 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:55665/ba/ji",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55665_ba%2Fji",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1859355 T4323 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1859355 T4323 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1859356 T4323 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1859357 T4322 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1859357 T4306 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1859357 T4290 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1859357 T4277 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1859367 T4270 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1859367 T4270 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1860868 T4271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1860869 T4271 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55668/ba/ji",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55668_ba%2Fji",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1860870 T4271 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1860870 T4271 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1860886 T4322 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1860886 T4290 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1860886 T4306 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1860886 T4270 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1860886 T4277 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1861358 T4323 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1861358 T4323 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty3-1384395536576/collection1
[junit4] 2> 1861358 T4323 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1861359 T4323 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1861359 T4323 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1861360 T4323 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty3-1384395536576/collection1/'
[junit4] 2> 1861362 T4323 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-jetty3-1384395536576/collection1/lib/README' to classloader
[junit4] 2> 1861363 T4323 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-jetty3-1384395536576/collection1/lib/classes/' to classloader
[junit4] 2> 1861430 T4323 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 1861526 T4323 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1861628 T4323 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1861640 T4323 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1862228 T4323 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1862232 T4323 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1862235 T4323 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1862240 T4323 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1862263 T4323 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4] 2> 1862263 T4323 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty3-1384395536576/collection1/, dataDir=./org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty3/
[junit4] 2> 1862264 T4323 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6237ea01
[junit4] 2> 1862265 T4323 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty3
[junit4] 2> 1862266 T4323 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty3/index/
[junit4] 2> 1862267 T4323 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1862269 T4323 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty3/index
[junit4] 2> 1862270 T4323 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=16.9248046875, floorSegmentMB=1.0458984375, forceMergeDeletesPctAllowed=14.621001701159022, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1862276 T4323 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3a6ae0ae; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 1862276 T4323 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1862280 T4323 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-constraint" (default)
[junit4] 2> 1862281 T4323 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-constraint" (default)
[junit4] 2> 1862281 T4323 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-float"
[junit4] 2> 1862281 T4323 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-float"
[junit4] 2> 1862282 T4323 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "external-version-failhard"
[junit4] 2> 1862282 T4323 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "external-version-failhard"
[junit4] 2> 1862282 T4323 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1862283 T4323 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1862284 T4323 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1862284 T4323 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1862285 T4323 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1862301 T4323 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1862310 T4323 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1862311 T4323 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1862312 T4323 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@45ba841e
[junit4] 2> 1862314 T4323 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.TestDistribDocBasedVersion-1384395521816/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3a6ae0ae; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4] 2> 1862315 T4323 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1862315 T4323 oass.SolrIndexSearcher.<init> Opening Searcher@40c530b2 main
[junit4] 2> 1862316 T4324 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@40c530b2 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1862318 T4323 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1862319 T4323 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55668/ba/ji collection:collection1 shard:shard1
[junit4] 2> 1862329 T4323 oasc.ZkController.register We are http://127.0.0.1:55668/ba/ji/collection1/ and leader is http://127.0.0.1:55661/ba/ji/collection1/
[junit4] 2> 1862329 T4323 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55668/ba/ji
[junit4] 2> 1862329 T4323 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 1862330 T4323 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C916 name=collection1 org.apache.solr.core.SolrCore@35685394 url=http://127.0.0.1:55668/ba/ji/collection1 node=127.0.0.1:55668_ba%2Fji C916_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:55668/ba/ji, core=collection1, node_name=127.0.0.1:55668_ba%2Fji}
[junit4] 2> 1862330 T4325 C916 P55668 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 1862331 T4323 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1862331 T4325 C916 P55668 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 1862331 T4325 C916 P55668 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 1862331 T4325 C916 P55668 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1862332 T4248 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1862332 T4248 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1862335 T4280 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 1862395 T4271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1862396 T4271 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "base_url":"http://127.0.0.1:55668/ba/ji",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55668_ba%2Fji",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 1862415 T4322 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1862415 T4306 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1862415 T4290 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1862415 T4270 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1862415 T4277 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1862614 T4248 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1862617 T4248 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:55672
[junit4] 2> 1862618 T4248 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1862618 T4248 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1862619 T4248 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty4-1384395541049
[junit4] 2> 1862619 T4248 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty4-1384395541049/'
[junit4] 2> 1862662 T4248 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty4-1384395541049/solr.xml
[junit4] 2> 1862755 T4248 oasc.CoreContainer.<init> New CoreContainer 385024585
[junit4] 2> 1862756 T4248 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.TestDistribDocBasedVersion-jetty4-1384395541049/]
[junit4] 2> 1862758 T4248 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1862758 T4248 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1862759 T4248 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1862759 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1862760 T4248 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1862760 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1862761 T4248 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1862761 T4248 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1862762 T4248 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1862769 T4248 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1862769 T4248 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1862770 T4248 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55650/solr
[junit4] 2> 1862770 T4248 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1862772 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1862806 T4337 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d0c2c02 name:ZooKeeperConnection Watcher:127.0.0.1:55650 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1862808 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1862812 T4248 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1862821 T4339 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c582376 name:ZooKeeperConnection Watcher:127.0.0.1:55650/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1862822 T4248 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1862831 T4248 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1863337 T4280 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 1863337 T4280 oass.Sol
[...truncated too long message...]
erElector.runIamLeaderProcess(LeaderElector.java:156)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1907668 T4339 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election/90727744918257676-core_node4-n_0000000001
[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:164)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:161)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:161)
[junit4] 2> at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:66)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:264)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1907669 T4339 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1907669 T4339 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:247)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:244)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:244)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> NOTE: test params are: codec=Asserting, sim=DefaultSimilarity, locale=sk, timezone=Arctic/Longyearbyen
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=3,free=131302120,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [DebugComponentTest, QueryEqualityTest, TestRealTimeGet, JsonLoaderTest, MoreLikeThisHandlerTest, PolyFieldTest, ZkControllerTest, EchoParamsTest, DirectUpdateHandlerOptimizeTest, TestLMDirichletSimilarityFactory, EnumFieldTest, TestManagedSchemaFieldResource, TestSolr4Spatial, ClusterStateTest, TestNonNRTOpen, AnalysisAfterCoreReloadTest, ResourceLoaderTest, TestTrie, SchemaVersionSpecificBehaviorTest, DistributedTermsComponentTest, TestXIncludeConfig, TestSolrXmlPersistence, CustomCollectionTest, SolrXmlInZkTest, TestWriterPerf, CollectionsAPIDistributedZkTest, ShardRoutingTest, SampleTest, MultiTermTest, HdfsLockFactoryTest, TestRemoteStreaming, TestSchemaNameResource, TestUniqueKeyFieldResource, DeleteShardTest, SolrTestCaseJ4Test, CurrencyFieldOpenExchangeTest, TestGroupingSearch, TestAtomicUpdateErrorCases, TestFieldTypeCollectionResource, SpellCheckCollatorTest, LoggingHandlerTest, TestIBSimilarityFactory, TestBadConfig, FileUtilsTest, CopyFieldTest, UpdateRequestProcessorFactoryTest, SoftAutoCommitTest, LukeRequestHandlerTest, TermVectorComponentDistributedTest, TestReload, TestSweetSpotSimilarityFactory, DirectSolrSpellCheckerTest, DefaultValueUpdateProcessorTest, PluginInfoTest, TestReloadAndDeleteDocs, TestSolrXmlPersistor, SyncSliceTest, ShardRoutingCustomTest, DocValuesTest, DocValuesMissingTest, PeerSyncTest, TestDistributedGrouping, TestSolrQueryParserDefaultOperatorResource, BlockCacheTest, TestSerializedLuceneMatchVersion, SearchHandlerTest, HdfsRecoveryZkTest, TestSchemaSimilarityResource, ScriptEngineTest, HdfsSyncSliceTest, HdfsCollectionsAPIDistributedZkTest, CSVRequestHandlerTest, TermVectorComponentTest, SolrCoreCheckLockOnStartupTest, TestLazyCores, FastVectorHighlighterTest, TestFaceting, TestLRUCache, BasicZkTest, TestRandomFaceting, UnloadDistributedZkTest, TestReplicationHandler, AliasIntegrationTest, TestDistribDocBasedVersion]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestDistribDocBasedVersion -Dtests.seed=5C465C9D1FE2E116 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sk -Dtests.timezone=Arctic/Longyearbyen -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J0 | TestDistribDocBasedVersion (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=4368, name=Lucene Merge Thread #0, state=RUNNABLE, group=TGRP-TestDistribDocBasedVersion]
[junit4] > Caused by: org.apache.lucene.index.MergePolicy$MergeException: java.lang.AssertionError
[junit4] > at __randomizedtesting.SeedInfo.seed([5C465C9D1FE2E116]:0)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:545)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:518)
[junit4] > Caused by: java.lang.AssertionError
[junit4] > at org.apache.lucene.index.IndexWriter._mergeInit(IndexWriter.java:3808)
[junit4] > at org.apache.lucene.index.IndexWriter.mergeInit(IndexWriter.java:3792)
[junit4] > at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3645)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=4369, name=Lucene Merge Thread #0, state=RUNNABLE, group=TGRP-TestDistribDocBasedVersion]
[junit4] > Caused by: org.apache.lucene.index.MergePolicy$MergeException: java.lang.AssertionError
[junit4] > at __randomizedtesting.SeedInfo.seed([5C465C9D1FE2E116]:0)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:545)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:518)
[junit4] > Caused by: java.lang.AssertionError
[junit4] > at org.apache.lucene.index.IndexWriter._mergeInit(IndexWriter.java:3808)
[junit4] > at org.apache.lucene.index.IndexWriter.mergeInit(IndexWriter.java:3792)
[junit4] > at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3645)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482)
[junit4] Completed on J0 in 64.88s, 1 test, 2 errors <<< FAILURES!
[...truncated 492 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:429: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:409: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/common-build.xml:489: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:1276: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:912: There were test failures: 335 suites, 1475 tests, 2 suite-level errors, 35 ignored (6 assumptions)
Total time: 63 minutes 55 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure