You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/02/13 17:32:13 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.7.0_51) - Build # 9355
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9355/
Java: 32bit/jdk1.7.0_51 -client -XX:+UseG1GC
3 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([598CB778DEC28F3]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
Error Message:
Captured an uncaught exception in thread: Thread[id=2982, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=2982, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
Caused by: java.lang.AssertionError: liveDocs.count()=12 info.docCount=16 info.getDelCount()=6
at __randomizedtesting.SeedInfo.seed([598CB778DEC28F3]:0)
at org.apache.lucene.codecs.lucene40.Lucene40LiveDocsFormat.readLiveDocs(Lucene40LiveDocsFormat.java:92)
at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:103)
at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:141)
at org.apache.lucene.index.ReadersAndUpdates.getReadOnlyClone(ReadersAndUpdates.java:235)
at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:100)
at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:382)
at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:275)
at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:250)
at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1444)
at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1632)
at org.apache.solr.handler.SnapPuller.openNewSearcherAndUpdateCommitPoint(SnapPuller.java:670)
at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:490)
at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:322)
at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:155)
at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:437)
at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:247)
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([598CB778DEC28F3]:0)
Build Log:
[...truncated 11388 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> 550303 T2385 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 550308 T2385 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeySafeLeaderTest-1392301878106
[junit4] 2> 550309 T2385 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 550310 T2386 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 550410 T2385 oasc.ZkTestServer.run start zk server on port:44801
[junit4] 2> 550411 T2385 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 550784 T2392 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d0c232 name:ZooKeeperConnection Watcher:127.0.0.1:44801 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 550785 T2385 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 550785 T2385 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 550789 T2385 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 550823 T2394 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13a27d name:ZooKeeperConnection Watcher:127.0.0.1:44801/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 550824 T2385 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 550824 T2385 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 550829 T2385 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 550831 T2385 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 550833 T2385 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 550835 T2385 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 550835 T2385 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 550839 T2385 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 550839 T2385 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 550842 T2385 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 550843 T2385 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 550846 T2385 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 550846 T2385 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 550848 T2385 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 550849 T2385 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 550851 T2385 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 550851 T2385 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 550853 T2385 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 550853 T2385 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 550855 T2385 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 550856 T2385 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 550858 T2385 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 550858 T2385 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 550860 T2385 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 550861 T2385 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 550863 T2385 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 550863 T2385 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 550947 T2385 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 550950 T2385 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38902
[junit4] 2> 550951 T2385 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 550951 T2385 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 550951 T2385 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392301878663
[junit4] 2> 550952 T2385 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392301878663/'
[junit4] 2> 550963 T2385 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392301878663/solr.xml
[junit4] 2> 551036 T2385 oasc.CoreContainer.<init> New CoreContainer 29297467
[junit4] 2> 551037 T2385 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392301878663/]
[junit4] 2> 551038 T2385 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 551038 T2385 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 551039 T2385 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 551039 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 551039 T2385 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 551040 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 551040 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 551040 T2385 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 551041 T2385 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 551043 T2385 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 551043 T2385 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 551043 T2385 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 551044 T2385 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44801/solr
[junit4] 2> 551044 T2385 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 551045 T2385 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 551046 T2405 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17a4f62 name:ZooKeeperConnection Watcher:127.0.0.1:44801 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 551047 T2385 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 551049 T2385 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 551050 T2407 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@126c49f name:ZooKeeperConnection Watcher:127.0.0.1:44801/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 551050 T2385 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 551051 T2385 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 551057 T2385 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 551061 T2385 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 551064 T2385 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38902_
[junit4] 2> 551066 T2385 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38902_
[junit4] 2> 551069 T2385 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 551071 T2385 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 551075 T2385 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38902_
[junit4] 2> 551075 T2385 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 551077 T2385 oasc.Overseer.start Overseer (id=91245895883751427-127.0.0.1:38902_-n_0000000000) starting
[junit4] 2> 551082 T2385 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 551087 T2409 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 551088 T2385 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 551089 T2409 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 551093 T2385 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 551097 T2385 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 551102 T2408 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 551110 T2410 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 551110 T2410 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 551114 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 551114 T2410 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 551117 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 551118 T2408 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:38902",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:38902_",
[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> 551119 T2408 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 551119 T2408 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 551125 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 551126 T2407 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> 552115 T2410 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 552116 T2410 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392301878663/collection1
[junit4] 2> 552116 T2410 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 552118 T2410 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 552118 T2410 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 552120 T2410 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 552121 T2410 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392301878663/collection1/'
[junit4] 2> 552122 T2410 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392301878663/collection1/lib/classes/' to classloader
[junit4] 2> 552123 T2410 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392301878663/collection1/lib/README' to classloader
[junit4] 2> 552171 T2410 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 552226 T2410 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 552227 T2410 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 552235 T2410 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 552608 T2410 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 552611 T2410 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 552613 T2410 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 552617 T2410 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 552636 T2410 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 552636 T2410 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392301878663/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/control/data/
[junit4] 2> 552636 T2410 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ea8228
[junit4] 2> 552637 T2410 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/control/data
[junit4] 2> 552637 T2410 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/control/data/index/
[junit4] 2> 552637 T2410 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 552638 T2410 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/control/data/index
[junit4] 2> 552638 T2410 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=13, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=26.4521484375, floorSegmentMB=1.8935546875, forceMergeDeletesPctAllowed=11.511867858016316, segmentsPerTier=32.0, maxCFSSegmentSizeMB=0.427734375, noCFSRatio=0.1729316607773767
[junit4] 2> 552643 T2410 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 552643 T2410 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 552645 T2410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 552645 T2410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 552646 T2410 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 552646 T2410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 552646 T2410 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 552646 T2410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 552647 T2410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 552647 T2410 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 552647 T2410 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 552648 T2410 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 552648 T2410 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 552648 T2410 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 552649 T2410 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 552649 T2410 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 552649 T2410 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 552650 T2410 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 552653 T2410 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 552657 T2410 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 552657 T2410 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 552658 T2410 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=75.89453125, floorSegmentMB=1.740234375, forceMergeDeletesPctAllowed=9.048855446218768, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 552659 T2410 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 552659 T2410 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 552659 T2410 oass.SolrIndexSearcher.<init> Opening Searcher@169e260[collection1] main
[junit4] 2> 552665 T2411 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@169e260[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 552669 T2410 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 552671 T2385 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 552671 T2385 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 552671 T2414 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38902 collection:control_collection shard:shard1
[junit4] 2> 552673 T2385 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 552675 T2414 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 552676 T2416 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cf22ec name:ZooKeeperConnection Watcher:127.0.0.1:44801/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 552676 T2385 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 552680 T2385 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 552685 T2385 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 552687 T2414 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 552690 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 552691 T2414 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 552692 T2414 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C566 name=collection1 org.apache.solr.core.SolrCore@1514174 url=http://127.0.0.1:38902/collection1 node=127.0.0.1:38902_ C566_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:38902, core=collection1, node_name=127.0.0.1:38902_}
[junit4] 2> 552693 T2414 C566 P38902 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38902/collection1/
[junit4] 2> 552693 T2414 C566 P38902 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 552693 T2414 C566 P38902 oasc.SyncStrategy.syncToMe http://127.0.0.1:38902/collection1/ has no replicas
[junit4] 2> 552694 T2414 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38902/collection1/ shard1
[junit4] 2> 552694 T2414 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 552696 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 552699 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 552706 T2416 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> 552706 T2407 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> 552711 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 552720 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 552771 T2385 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 552772 T2385 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 552776 T2385 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33212
[junit4] 2> 552776 T2385 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 552777 T2385 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 552778 T2385 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392301880482
[junit4] 2> 552778 T2385 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392301880482/'
[junit4] 2> 552799 T2385 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392301880482/solr.xml
[junit4] 2> 552838 T2407 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> 552838 T2416 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> 552859 T2414 oasc.ZkController.register We are http://127.0.0.1:38902/collection1/ and leader is http://127.0.0.1:38902/collection1/
[junit4] 2> 552859 T2414 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38902
[junit4] 2> 552860 T2414 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 552860 T2414 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 552860 T2414 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 552860 T2385 oasc.CoreContainer.<init> New CoreContainer 16654236
[junit4] 2> 552861 T2385 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392301880482/]
[junit4] 2> 552861 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 552861 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 552862 T2414 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 552862 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 552862 T2385 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 552863 T2385 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 552863 T2385 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 552863 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 552863 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 552864 T2385 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 552864 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 552865 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 552865 T2385 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 552864 T2408 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:38902",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:38902_",
[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":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 552865 T2385 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 552868 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 552868 T2385 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 552869 T2385 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 552869 T2385 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 552869 T2385 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44801/solr
[junit4] 2> 552870 T2385 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 552871 T2385 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 552872 T2427 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c6ba1 name:ZooKeeperConnection Watcher:127.0.0.1:44801 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 552873 T2385 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 552876 T2385 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 552877 T2429 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ff2e41 name:ZooKeeperConnection Watcher:127.0.0.1:44801/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 552878 T2385 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 552885 T2385 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 552970 T2407 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> 552971 T2429 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> 552971 T2416 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> 553890 T2385 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33212_
[junit4] 2> 553891 T2385 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33212_
[junit4] 2> 553894 T2407 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 553894 T2416 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 553895 T2429 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 553903 T2430 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 553903 T2430 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 553905 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 553905 T2430 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 553907 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 553905 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 553908 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 553908 T2408 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:33212",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:33212_",
[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":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 553909 T2408 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 553909 T2408 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 553912 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 554017 T2429 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> 554017 T2416 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> 554017 T2407 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> 554907 T2430 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 554908 T2430 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392301880482/collection1
[junit4] 2> 554909 T2430 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 554910 T2430 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 554910 T2430 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 554912 T2430 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 554913 T2430 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392301880482/collection1/'
[junit4] 2> 554914 T2430 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392301880482/collection1/lib/classes/' to classloader
[junit4] 2> 554915 T2430 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392301880482/collection1/lib/README' to classloader
[junit4] 2> 554968 T2430 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 555016 T2430 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 555019 T2430 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 555026 T2430 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 555402 T2430 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 555405 T2430 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 555407 T2430 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 555411 T2430 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 555447 T2430 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 555447 T2430 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392301880482/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty1/
[junit4] 2> 555448 T2430 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ea8228
[junit4] 2> 555449 T2430 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty1
[junit4] 2> 555449 T2430 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty1/index/
[junit4] 2> 555450 T2430 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 555451 T2430 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty1/index
[junit4] 2> 555452 T2430 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=13, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=26.4521484375, floorSegmentMB=1.8935546875, forceMergeDeletesPctAllowed=11.511867858016316, segmentsPerTier=32.0, maxCFSSegmentSizeMB=0.427734375, noCFSRatio=0.1729316607773767
[junit4] 2> 555456 T2430 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 555457 T2430 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 555464 T2430 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 555465 T2430 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 555466 T2430 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 555466 T2430 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 555467 T2430 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 555467 T2430 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 555468 T2430 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 555469 T2430 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 555469 T2430 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 555470 T2430 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 555472 T2430 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 555472 T2430 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 555473 T2430 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 555474 T2430 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 555475 T2430 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 555477 T2430 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 555481 T2430 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 555487 T2430 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 555487 T2430 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 555489 T2430 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=75.89453125, floorSegmentMB=1.740234375, forceMergeDeletesPctAllowed=9.048855446218768, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 555491 T2430 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 555491 T2430 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 555492 T2430 oass.SolrIndexSearcher.<init> Opening Searcher@83fef[collection1] main
[junit4] 2> 555500 T2431 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@83fef[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 555502 T2430 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 555503 T2385 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 555504 T2385 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 555503 T2434 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33212 collection:collection1 shard:shard3
[junit4] 2> 555506 T2434 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 555516 T2434 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
[junit4] 2> 555517 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555517 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555518 T2434 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 555518 T2434 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 555518 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> ASYNC NEW_CORE C567 name=collection1 org.apache.solr.core.SolrCore@e72ff4 url=http://127.0.0.1:33212/collection1 node=127.0.0.1:33212_ C567_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:33212, core=collection1, node_name=127.0.0.1:33212_}
[junit4] 2> 555518 T2434 C567 P33212 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33212/collection1/
[junit4] 2> 555519 T2434 C567 P33212 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 555519 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 555519 T2434 C567 P33212 oasc.SyncStrategy.syncToMe http://127.0.0.1:33212/collection1/ has no replicas
[junit4] 2> 555519 T2434 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33212/collection1/ shard3
[junit4] 2> 555519 T2434 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 555521 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555522 T2429 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> 555522 T2416 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> 555522 T2407 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> 555526 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 555529 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555583 T2385 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 555584 T2385 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 555586 T2385 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51025
[junit4] 2> 555587 T2385 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 555587 T2385 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 555588 T2385 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392301883302
[junit4] 2> 555589 T2385 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392301883302/'
[junit4] 2> 555632 T2416 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> 555632 T2407 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> 555632 T2429 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> 555632 T2385 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392301883302/solr.xml
[junit4] 2> 555677 T2434 oasc.ZkController.register We are http://127.0.0.1:33212/collection1/ and leader is http://127.0.0.1:33212/collection1/
[junit4] 2> 555678 T2434 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33212
[junit4] 2> 555678 T2434 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 555678 T2434 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 555678 T2434 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 555679 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555679 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555680 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555680 T2434 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 555680 T2385 oasc.CoreContainer.<init> New CoreContainer 10012
[junit4] 2> 555681 T2385 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392301883302/]
[junit4] 2> 555681 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 555682 T2408 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:33212",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:33212_",
[junit4] 2> "shard":"shard3",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 555682 T2385 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 555683 T2385 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 555683 T2385 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 555684 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 555684 T2385 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 555684 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 555685 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 555685 T2385 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 555685 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555685 T2385 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 555688 T2385 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 555688 T2385 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 555689 T2385 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 555689 T2385 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44801/solr
[junit4] 2> 555689 T2385 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 555690 T2385 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 555692 T2445 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1908c8d name:ZooKeeperConnection Watcher:127.0.0.1:44801 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 555693 T2385 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 555697 T2385 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 555698 T2447 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b8afbf name:ZooKeeperConnection Watcher:127.0.0.1:44801/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 555699 T2385 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 555705 T2385 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 555788 T2416 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> 555789 T2429 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> 555789 T2407 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> 555788 T2447 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> 556710 T2385 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51025_
[junit4] 2> 556712 T2385 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51025_
[junit4] 2> 556716 T2416 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 556716 T2429 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 556717 T2447 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 556718 T2407 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 556730 T2448 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 556731 T2448 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 556732 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 556733 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 556732 T2448 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 556733 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 556735 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 556737 T2408 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:51025",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51025_",
[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":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 556737 T2408 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 556738 T2408 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 556741 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 556845 T2429 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> 556845 T2447 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> 556845 T2407 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> 556845 T2416 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> 557734 T2448 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 557735 T2448 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392301883302/collection1
[junit4] 2> 557735 T2448 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 557736 T2448 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 557737 T2448 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 557739 T2448 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 557739 T2448 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392301883302/collection1/'
[junit4] 2> 557741 T2448 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392301883302/collection1/lib/classes/' to classloader
[junit4] 2> 557741 T2448 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392301883302/collection1/lib/README' to classloader
[junit4] 2> 557807 T2448 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 557851 T2448 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 557853 T2448 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 557861 T2448 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 558226 T2448 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 558228 T2448 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 558230 T2448 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 558234 T2448 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 558270 T2448 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 558270 T2448 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392301883302/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty2/
[junit4] 2> 558271 T2448 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ea8228
[junit4] 2> 558272 T2448 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty2
[junit4] 2> 558272 T2448 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty2/index/
[junit4] 2> 558273 T2448 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 558273 T2448 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty2/index
[junit4] 2> 558274 T2448 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=13, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=26.4521484375, floorSegmentMB=1.8935546875, forceMergeDeletesPctAllowed=11.511867858016316, segmentsPerTier=32.0, maxCFSSegmentSizeMB=0.427734375, noCFSRatio=0.1729316607773767
[junit4] 2> 558278 T2448 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 558278 T2448 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 558285 T2448 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 558286 T2448 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 558287 T2448 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 558287 T2448 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 558288 T2448 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 558289 T2448 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 558289 T2448 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 558290 T2448 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 558291 T2448 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 558292 T2448 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 558294 T2448 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 558294 T2448 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 558295 T2448 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 558296 T2448 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 558296 T2448 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 558297 T2448 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 558315 T2448 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 558319 T2448 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 558319 T2448 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 558320 T2448 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=75.89453125, floorSegmentMB=1.740234375, forceMergeDeletesPctAllowed=9.048855446218768, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 558321 T2448 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 558321 T2448 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 558321 T2448 oass.SolrIndexSearcher.<init> Opening Searcher@7d433a[collection1] main
[junit4] 2> 558327 T2449 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7d433a[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 558330 T2448 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 558331 T2385 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 558332 T2385 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 558331 T2452 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51025 collection:collection1 shard:shard2
[junit4] 2> 558334 T2452 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 558339 T2452 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 558341 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558341 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558341 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558341 T2452 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 558342 T2452 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C568 name=collection1 org.apache.solr.core.SolrCore@9ccb08 url=http://127.0.0.1:51025/collection1 node=127.0.0.1:51025_ C568_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:51025, core=collection1, node_name=127.0.0.1:51025_}
[junit4] 2> 558342 T2452 C568 P51025 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51025/collection1/
[junit4] 2> 558342 T2452 C568 P51025 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 558342 T2452 C568 P51025 oasc.SyncStrategy.syncToMe http://127.0.0.1:51025/collection1/ has no replicas
[junit4] 2> 558343 T2452 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51025/collection1/ shard2
[junit4] 2> 558342 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 558343 T2452 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 558347 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558347 T2407 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> 558348 T2447 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> 558348 T2416 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> 558348 T2429 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> 558352 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 558354 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558409 T2385 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 558410 T2385 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 558413 T2385 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44840
[junit4] 2> 558413 T2385 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 558414 T2385 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 558414 T2385 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392301886130
[junit4] 2> 558415 T2385 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392301886130/'
[junit4] 2> 558437 T2385 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392301886130/solr.xml
[junit4] 2> 558457 T2416 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> 558457 T2407 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> 558457 T2447 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> 558457 T2429 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> 558483 T2385 oasc.CoreContainer.<init> New CoreContainer 5766705
[junit4] 2> 558484 T2385 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392301886130/]
[junit4] 2> 558485 T2385 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 558485 T2385 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 558486 T2385 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 558486 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 558486 T2385 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 558487 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 558487 T2385 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 558487 T2385 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 558488 T2385 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 558490 T2385 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 558490 T2385 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 558491 T2385 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 558491 T2385 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44801/solr
[junit4] 2> 558491 T2385 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 558492 T2385 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 558493 T2463 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f17567 name:ZooKeeperConnection Watcher:127.0.0.1:44801 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 558494 T2385 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 558496 T2385 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 558497 T2465 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19bb4ef name:ZooKeeperConnection Watcher:127.0.0.1:44801/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 558497 T2385 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 558500 T2452 oasc.ZkController.register We are http://127.0.0.1:51025/collection1/ and leader is http://127.0.0.1:51025/collection1/
[junit4] 2> 558500 T2452 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51025
[junit4] 2> 558501 T2452 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 558501 T2452 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 558501 T2452 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 558502 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558502 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558502 T2452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 558502 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558503 T2385 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 558505 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 558506 T2408 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:51025",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51025_",
[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":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 558509 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 558612 T2416 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> 558612 T2429 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> 558613 T2407 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> 558612 T2465 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> 558612 T2447 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> 559507 T2385 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44840_
[junit4] 2> 559510 T2385 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44840_
[junit4] 2> 559515 T2407 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 559516 T2465 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 559515 T2447 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 559515 T2416 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 559515 T2429 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 559526 T2466 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 559527 T2466 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 559529 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 559529 T2466 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 559529 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 559530 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 559533 T2408 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 559534 T2408 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44840",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:44840_",
[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":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 559535 T2408 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 559535 T2408 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 559539 T2407 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 559644 T2416 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> 559644 T2407 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> 559644 T2465 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> 559644 T2429 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> 559644 T2447 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> 560530 T2466 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 560530 T2466 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392301886130/collection1
[junit4] 2> 560531 T2466 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 560532 T2466 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 560533 T2466 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 560535 T2466 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 560535 T2466 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392301886130/collection1/'
[junit4] 2> 560536 T2466 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392301886130/collection1/lib/classes/' to classloader
[junit4] 2> 560537 T2466 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392301886130/collection1/lib/README' to classloader
[junit4] 2> 560585 T2466 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 560630 T2466 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 560632 T2466 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 560640 T2466 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 561018 T2466 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 561021 T2466 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 561023 T2466 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 561027 T2466 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 561061 T2466 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 561061 T2466 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392301886130/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty3/
[junit4] 2> 561062 T2466 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ea8228
[junit4] 2> 561063 T2466 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty3
[junit4] 2> 561064 T2466 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty3/index/
[junit4] 2> 561064 T2466 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 561065 T2466 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392301878106/jetty3/index
[junit4] 2> 561066 T2466 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=13, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=26.4521484375, floorSegmentMB=1.8935546875, forceMergeDeletesPctAllowed=11.511867858016316, segmentsPerTier=32.0, maxCFSSegmentSizeMB=0.427734375, noCFSRatio=0.1729316
[...truncated too long message...]
mpl.lockAndDoSelect(SelectorImpl.java:87)
[junit4] 2> at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 81) Thread[id=2986, name=qtp17962019-2986 Selector1, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.nio.ch.IOUtil.drain(Native Method)
[junit4] 2> at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:90)
[junit4] 2> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
[junit4] 2> at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 82) Thread[id=3024, name=coreZkRegister-2175-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 83) Thread[id=3026, name=HashSessionScavenger-77, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:552)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> 84) Thread[id=2838, name=qtp30371513-2838 Selector1, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:82)
[junit4] 2> at sun.nio.ch.SelectorImpl.selectNow(SelectorImpl.java:106)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:536)
[junit4] 2> at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> NOTE: test params are: codec=Lucene3x, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=sr_RS, timezone=Asia/Yakutsk
[junit4] 2> NOTE: Linux 3.8.0-35-generic i386/Oracle Corporation 1.7.0_51 (32-bit)/cpus=8,threads=98,free=316527480,total=524288000
[junit4] 2> NOTE: All tests run in this JVM: [HighlighterTest, TestAtomicUpdateErrorCases, TestSolrDeletionPolicy2, TestSchemaSimilarityResource, HdfsSyncSliceTest, ConvertedLegacyTest, ShardRoutingCustomTest, NotRequiredUniqueKeyTest, SolrIndexConfigTest, TestAnalyzedSuggestions, TestHighlightDedupGrouping, TestSweetSpotSimilarityFactory, TestReload, AlternateDirectoryTest, BadCopyFieldTest, TestStressReorder, TestFieldResource, LeaderElectionIntegrationTest, TestCSVLoader, TestCopyFieldCollectionResource, TestIBSimilarityFactory, TestSolr4Spatial, HdfsUnloadDistributedZkTest, ZkSolrClientTest, SpellingQueryConverterTest, TestQueryTypes, TestUpdate, PingRequestHandlerTest, CursorMarkTest, TestBinaryField, HighlighterConfigTest, FileUtilsTest, HdfsRecoveryZkTest, TestXIncludeConfig, TestCodecSupport, TestComponentsName, PreAnalyzedFieldTest, CachingDirectoryFactoryTest, MultiTermTest, BlockDirectoryTest, TestQuerySenderNoQuery, TestDFRSimilarityFactory, SuggesterTSTTest, TestRandomMergePolicy, TestCSVResponseWriter, TestCoreDiscovery, TestNumberUtils, OutputWriterTest, TermVectorComponentDistributedTest, DefaultValueUpdateProcessorTest, TestPhraseSuggestions, DirectSolrConnectionTest, CurrencyFieldXmlFileTest, NoCacheHeaderTest, TestFieldTypeResource, DirectUpdateHandlerTest, ChaosMonkeyNothingIsSafeTest, SolrCoreCheckLockOnStartupTest, TestBinaryResponseWriter, TestSolrXmlPersistence, PreAnalyzedUpdateProcessorTest, TestDefaultSimilarityFactory, ZkNodePropsTest, TestIndexSearcher, TestHashPartitioner, CurrencyFieldOpenExchangeTest, TestUtils, UniqFieldsUpdateProcessorFactoryTest, TestFastOutputStream, TestCloudManagedSchema, TestJmxIntegration, SpellCheckComponentTest, TimeZoneUtilsTest, TestClassNameShortening, CollectionsAPIDistributedZkTest, TestInfoStreamLogging, TestUniqueKeyFieldResource, DocumentAnalysisRequestHandlerTest, FieldAnalysisRequestHandlerTest, TestFuzzyAnalyzedSuggestions, RequestHandlersTest, SuggesterWFSTTest, TestZkChroot, DistributedQueryComponentCustomSortTest, SolrRequestParserTest, AssignTest, NumericFieldsTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=598CB778DEC28F3 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sr_RS -Dtests.timezone=Asia/Yakutsk -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J1 | ChaosMonkeySafeLeaderTest (suite) <<<
[junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4] > at __randomizedtesting.SeedInfo.seed([598CB778DEC28F3]:0)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=2982, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] > Caused by: java.lang.AssertionError: liveDocs.count()=12 info.docCount=16 info.getDelCount()=6
[junit4] > at __randomizedtesting.SeedInfo.seed([598CB778DEC28F3]:0)
[junit4] > at org.apache.lucene.codecs.lucene40.Lucene40LiveDocsFormat.readLiveDocs(Lucene40LiveDocsFormat.java:92)
[junit4] > at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:103)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:141)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReadOnlyClone(ReadersAndUpdates.java:235)
[junit4] > at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:100)
[junit4] > at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:382)
[junit4] > at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:275)
[junit4] > at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:250)
[junit4] > at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1444)
[junit4] > at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1632)
[junit4] > at org.apache.solr.handler.SnapPuller.openNewSearcherAndUpdateCommitPoint(SnapPuller.java:670)
[junit4] > at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:490)
[junit4] > at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:322)
[junit4] > at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:155)
[junit4] > at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:437)
[junit4] > at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:247)
[junit4] Completed on J1 in 7225.27s, 1 test, 3 errors <<< FAILURES!
[...truncated 11 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:439: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1308: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:941: There were test failures: 362 suites, 1562 tests, 2 suite-level errors, 1 error, 36 ignored (8 assumptions)
Total time: 154 minutes 13 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_51 -client -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-Linux (32bit/ibm-j9-jdk6) - Build # 9356
- Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9356/
Java: 32bit/ibm-j9-jdk6 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
3 tests failed.
REGRESSION: org.apache.solr.handler.component.DistributedQueryElevationComponentTest.testDistribSearch
Error Message:
.responseHeader.params.sort!=fl (unordered or missing)
Stack Trace:
junit.framework.AssertionFailedError: .responseHeader.params.sort!=fl (unordered or missing)
at __randomizedtesting.SeedInfo.seed([F7F988A7583FB650:761F06BF2F60D66C]:0)
at junit.framework.Assert.fail(Assert.java:50)
at org.apache.solr.BaseDistributedSearchTestCase.compareSolrResponses(BaseDistributedSearchTestCase.java:840)
at org.apache.solr.BaseDistributedSearchTestCase.compareResponses(BaseDistributedSearchTestCase.java:859)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:562)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:542)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:521)
at org.apache.solr.handler.component.DistributedQueryElevationComponentTest.doTest(DistributedQueryElevationComponentTest.java:81)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:738)
REGRESSION: org.apache.solr.handler.component.TermVectorComponentDistributedTest.testDistribSearch
Error Message:
.termVectors.0.test_offtv!=test_basictv (unordered or missing)
Stack Trace:
junit.framework.AssertionFailedError: .termVectors.0.test_offtv!=test_basictv (unordered or missing)
at __randomizedtesting.SeedInfo.seed([F7F988A7583FB650:761F06BF2F60D66C]:0)
at junit.framework.Assert.fail(Assert.java:50)
at org.apache.solr.BaseDistributedSearchTestCase.compareSolrResponses(BaseDistributedSearchTestCase.java:840)
at org.apache.solr.BaseDistributedSearchTestCase.compareResponses(BaseDistributedSearchTestCase.java:859)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:562)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:542)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:521)
at org.apache.solr.handler.component.TermVectorComponentDistributedTest.doTest(TermVectorComponentDistributedTest.java:127)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:873)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:738)
REGRESSION: org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testDupeDetection
Error Message:
expected:<1> but was:<2>
Stack Trace:
java.lang.AssertionError: expected:<1> but was:<2>
at __randomizedtesting.SeedInfo.seed([F7F988A7583FB650:ACC9736F5B78152C]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.checkNumDocs(SignatureUpdateProcessorFactoryTest.java:71)
at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testDupeDetection(SignatureUpdateProcessorFactoryTest.java:119)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:738)
Build Log:
[...truncated 9301 lines...]
[junit4] Suite: org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest
[junit4] 2> 59570 T150 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822
[junit4] 2> 59571 T150 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/'
[junit4] 2> 59573 T150 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 59573 T150 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 59664 T150 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 59733 T150 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 59734 T150 oass.IndexSchema.readSchema Reading Solr Schema from schema12.xml
[junit4] 2> 59742 T150 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 60310 T150 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 60315 T150 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 60319 T150 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (2)
[junit4] 2> 60349 T150 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 60356 T150 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 60363 T150 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 60364 T150 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr
[junit4] 2> 60365 T150 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/'
[junit4] 2> 60429 T150 oasc.CoreContainer.<init> New CoreContainer 134940683
[junit4] 2> 60430 T150 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/]
[junit4] 2> 60431 T150 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 60432 T150 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 60433 T150 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 60433 T150 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 60434 T150 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 60434 T150 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 60435 T150 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 60436 T150 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 60436 T150 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 60442 T150 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 60442 T150 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 60443 T150 oasc.CoreContainer.load Host Name:
[junit4] 2> 60449 T151 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1
[junit4] 2> 60449 T151 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/'
[junit4] 2> 60451 T151 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 60452 T151 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 60523 T151 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 60596 T151 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 60598 T151 oass.IndexSchema.readSchema Reading Solr Schema from schema12.xml
[junit4] 2> 60607 T151 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 61144 T151 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 61148 T151 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 61149 T151 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (2)
[junit4] 2> 61177 T151 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 61187 T151 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 61191 T151 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 61192 T151 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822/
[junit4] 2> 61192 T151 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 61193 T151 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822
[junit4] 2> 61194 T151 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822/index/
[junit4] 2> 61194 T151 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822/index' doesn't exist. Creating new index...
[junit4] 2> 61195 T151 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822/index
[junit4] 2> 61196 T151 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=20, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 61197 T151 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_1,generation=1}
[junit4] 2> 61197 T151 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 61198 T151 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 61199 T151 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 61200 T151 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 61200 T151 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 61201 T151 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 61202 T151 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 61202 T151 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 61203 T151 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 61203 T151 oasup.UniqFieldsUpdateProcessorFactory.init WARN Use of the 'fields' init param in UniqFieldsUpdateProcessorFactory is deprecated, please use 'fieldName' (or another FieldMutatingUpdateProcessorFactory selector option) instead
[junit4] 2> 61204 T151 oasup.UniqFieldsUpdateProcessorFactory.init Replacing 'fields' init param with (individual) 'fieldName' params
[junit4] 2> 61204 T151 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 61205 T151 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 61206 T151 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 61206 T151 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 61207 T151 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 61208 T151 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 61209 T151 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 61209 T151 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 61210 T151 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 61211 T151 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 61211 T151 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 61212 T151 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 61212 T151 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 61213 T151 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 61213 T151 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 61214 T151 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 61214 T151 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 61215 T151 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 61215 T151 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 61216 T151 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 61217 T151 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 61217 T151 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 61218 T151 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 61218 T151 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 61219 T151 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 61220 T151 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 61220 T151 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 61222 T151 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 61224 T151 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 61226 T151 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 61226 T151 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 61227 T151 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=48, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 61228 T151 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_1,generation=1}
[junit4] 2> 61229 T151 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 61230 T151 oass.SolrIndexSearcher.<init> Opening Searcher@1ee11ee1[collection1] main
[junit4] 2> 61231 T151 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 61327 T151 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 61367 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ee11ee1[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 61367 T151 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 61370 T150 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 61378 T150 oas.SolrTestCaseJ4.setUp ###Starting testMultiThreaded
[junit4] 2> ASYNC NEW_CORE C1338 name=collection1 org.apache.solr.core.SolrCore@4db04db
[junit4] 2> 61379 T150 C1338 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 61381 T150 C1338 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4] 2> 61385 T150 C1338 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61386 T150 C1338 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_2,generation=2}
[junit4] 2> 61387 T150 C1338 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 61388 T150 C1338 oass.SolrIndexSearcher.<init> Opening Searcher@549e549e[collection1] main
[junit4] 2> 61389 T150 C1338 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61389 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@549e549e[collection1] main{StandardDirectoryReader(segments_2:2:nrt)}
[junit4] 2> 61391 T150 C1338 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 6
[junit4] 2> 61527 T161 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61613 T161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_3,generation=3}
[junit4] 2> 61614 T161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 61681 T161 oass.SolrIndexSearcher.<init> Opening Searcher@76237623[collection1] main
[junit4] 2> 61682 T161 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61682 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@76237623[collection1] main{StandardDirectoryReader(segments_3:16:nrt _3(4.7):C51/50:delGen=1 _2(4.7):C48/47:delGen=1)}
[junit4] 2> 61683 T163 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61728 T163 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_4,generation=4}
[junit4] 2> 61729 T163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 61737 T163 oass.SolrIndexSearcher.<init> Opening Searcher@1e011e01[collection1] main
[junit4] 2> 61738 T163 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61738 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e011e01[collection1] main{StandardDirectoryReader(segments_4:24:nrt _6(4.7):C16/12:delGen=1)}
[junit4] 2> 61739 T162 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61740 T162 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_5,generation=5}
[junit4] 2> 61741 T162 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 61745 T162 oass.SolrIndexSearcher.<init> Opening Searcher@5a185a18[collection1] main
[junit4] 2> 61746 T162 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61746 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5a185a18[collection1] main{StandardDirectoryReader(segments_5:27:nrt _6(4.7):C16/13:delGen=1 _7(4.7):C1)}
[junit4] 2> 61747 T161 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61748 T161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_5,generation=5}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_6,generation=6}
[junit4] 2> 61749 T161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4] 2> 61753 T161 oass.SolrIndexSearcher.<init> Opening Searcher@5af05af0[collection1] main
[junit4] 2> 61754 T161 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61754 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5af05af0[collection1] main{StandardDirectoryReader(segments_6:31:nrt _6(4.7):C16/14:delGen=2 _8(4.7):C1)}
[junit4] 2> 61755 T163 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61756 T163 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_6,generation=6}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_7,generation=7}
[junit4] 2> 61757 T163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 7
[junit4] 2> 61761 T163 oass.SolrIndexSearcher.<init> Opening Searcher@739f739f[collection1] main
[junit4] 2> 61762 T163 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61762 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@739f739f[collection1] main{StandardDirectoryReader(segments_7:34:nrt _6(4.7):C16/15:delGen=3 _8(4.7):C1 _9(4.7):C1)}
[junit4] 2> 61762 T162 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61764 T162 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_7,generation=7}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_8,generation=8}
[junit4] 2> 61765 T162 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 8
[junit4] 2> 61775 T162 oass.SolrIndexSearcher.<init> Opening Searcher@75f275f2[collection1] main
[junit4] 2> 61776 T162 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61776 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@75f275f2[collection1] main{StandardDirectoryReader(segments_8:38:nrt _6(4.7):C16/15:delGen=4 _a(4.7):C1)}
[junit4] 2> 61777 T161 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61778 T161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_8,generation=8}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_9,generation=9}
[junit4] 2> 61779 T161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 9
[junit4] 2> 61783 T161 oass.SolrIndexSearcher.<init> Opening Searcher@44044404[collection1] main
[junit4] 2> 61784 T161 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61784 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@44044404[collection1] main{StandardDirectoryReader(segments_9:42:nrt _b(4.7):C1)}
[junit4] 2> 61785 T163 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61787 T163 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_9,generation=9}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_a,generation=10}
[junit4] 2> 61788 T163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 10
[junit4] 2> 61791 T163 oass.SolrIndexSearcher.<init> Opening Searcher@1aa01aa[collection1] main
[junit4] 2> 61793 T163 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61793 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1aa01aa[collection1] main{StandardDirectoryReader(segments_a:44:nrt _b(4.7):C1 _c(4.7):C1)}
[junit4] 2> 61793 T162 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61795 T162 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_a,generation=10}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_b,generation=11}
[junit4] 2> 61795 T162 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 11
[junit4] 2> 61798 T162 oass.SolrIndexSearcher.<init> Opening Searcher@5fb05fb0[collection1] main
[junit4] 2> 61799 T162 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61799 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5fb05fb0[collection1] main{StandardDirectoryReader(segments_b:48:nrt _b(4.7):C1 _d(4.7):C1)}
[junit4] 2> 61800 T161 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61802 T161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_b,generation=11}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_c,generation=12}
[junit4] 2> 61803 T161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 12
[junit4] 2> 61807 T161 oass.SolrIndexSearcher.<init> Opening Searcher@21042104[collection1] main
[junit4] 2> 61808 T161 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61808 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@21042104[collection1] main{StandardDirectoryReader(segments_c:52:nrt _b(4.7):C1 _e(4.7):C1)}
[junit4] 2> 61809 T163 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61810 T163 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_c,generation=12}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_d,generation=13}
[junit4] 2> 61811 T163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 13
[junit4] 2> 61815 T163 oass.SolrIndexSearcher.<init> Opening Searcher@4feb4feb[collection1] main
[junit4] 2> 61817 T163 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61817 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4feb4feb[collection1] main{StandardDirectoryReader(segments_d:54:nrt _b(4.7):C1 _e(4.7):C1 _f(4.7):C1)}
[junit4] 2> 61817 T162 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61819 T162 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_d,generation=13}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_e,generation=14}
[junit4] 2> 61820 T162 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 14
[junit4] 2> 61823 T162 oass.SolrIndexSearcher.<init> Opening Searcher@1e821e82[collection1] main
[junit4] 2> 61824 T162 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61824 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e821e82[collection1] main{StandardDirectoryReader(segments_e:58:nrt _b(4.7):C1 _e(4.7):C1 _g(4.7):C1)}
[junit4] 2> 61825 T161 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61826 T161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_e,generation=14}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_f,generation=15}
[junit4] 2> 61827 T161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 15
[junit4] 2> 61831 T161 oass.SolrIndexSearcher.<init> Opening Searcher@5bdf5bdf[collection1] main
[junit4] 2> 61832 T161 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61832 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5bdf5bdf[collection1] main{StandardDirectoryReader(segments_f:62:nrt _b(4.7):C1 _e(4.7):C1 _h(4.7):C1)}
[junit4] 2> 61832 T163 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61834 T163 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_f,generation=15}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_g,generation=16}
[junit4] 2> 61835 T163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 16
[junit4] 2> 61850 T163 oass.SolrIndexSearcher.<init> Opening Searcher@18761876[collection1] main
[junit4] 2> 61851 T163 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61851 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18761876[collection1] main{StandardDirectoryReader(segments_g:66:nrt _e(4.7):C1 _h(4.7):C1 _i(4.7):C1)}
[junit4] 2> 61852 T162 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61854 T162 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_g,generation=16}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_h,generation=17}
[junit4] 2> 61854 T162 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 17
[junit4] 2> 61858 T162 oass.SolrIndexSearcher.<init> Opening Searcher@42c542c5[collection1] main
[junit4] 2> 61859 T162 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61859 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@42c542c5[collection1] main{StandardDirectoryReader(segments_h:70:nrt _e(4.7):C1 _h(4.7):C1 _j(4.7):C1)}
[junit4] 2> 61860 T161 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61861 T161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_h,generation=17}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_i,generation=18}
[junit4] 2> 61862 T161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 18
[junit4] 2> 61866 T161 oass.SolrIndexSearcher.<init> Opening Searcher@1bc51bc5[collection1] main
[junit4] 2> 61867 T161 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61867 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1bc51bc5[collection1] main{StandardDirectoryReader(segments_i:74:nrt _e(4.7):C1 _k(4.7):C1)}
[junit4] 2> 61867 T163 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61869 T163 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_i,generation=18}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_j,generation=19}
[junit4] 2> 61870 T163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 19
[junit4] 2> 61872 T163 oass.SolrIndexSearcher.<init> Opening Searcher@74d174d1[collection1] main
[junit4] 2> 61873 T163 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61873 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@74d174d1[collection1] main{StandardDirectoryReader(segments_j:76:nrt _e(4.7):C1 _k(4.7):C1 _l(4.7):C1)}
[junit4] 2> 61874 T162 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61876 T162 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_j,generation=19}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_k,generation=20}
[junit4] 2> 61877 T162 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 20
[junit4] 2> 61881 T162 oass.SolrIndexSearcher.<init> Opening Searcher@237e237e[collection1] main
[junit4] 2> 61882 T162 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61882 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@237e237e[collection1] main{StandardDirectoryReader(segments_k:80:nrt _e(4.7):C1 _k(4.7):C1 _m(4.7):C1)}
[junit4] 2> 61883 T161 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61884 T161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_k,generation=20}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_l,generation=21}
[junit4] 2> 61885 T161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 21
[junit4] 2> 61890 T161 oass.SolrIndexSearcher.<init> Opening Searcher@40f040f0[collection1] main
[junit4] 2> 61891 T161 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61891 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@40f040f0[collection1] main{StandardDirectoryReader(segments_l:84:nrt _e(4.7):C1 _k(4.7):C1 _n(4.7):C1)}
[junit4] 2> 61892 T163 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61893 T163 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_l,generation=21}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_m,generation=22}
[junit4] 2> 61894 T163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 22
[junit4] 2> 61895 T163 oass.SolrIndexSearcher.<init> Opening Searcher@4bf44bf4[collection1] main
[junit4] 2> 61895 T163 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61896 T162 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61896 T162 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 61897 T162 oasc.SolrCore.getSearcher WARN [collection1] PERFORMANCE WARNING: Overlapping onDeckSearchers=2
[junit4] 2> 61898 T162 oass.SolrIndexSearcher.<init> Opening Searcher@7b597b59[collection1] main
[junit4] 2> 61899 T162 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61942 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4bf44bf4[collection1] main{StandardDirectoryReader(segments_l:84:nrt _e(4.7):C1 _k(4.7):C1 _n(4.7):C1)}
[junit4] 2> 61943 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7b597b59[collection1] main{StandardDirectoryReader(segments_l:84:nrt _e(4.7):C1 _k(4.7):C1 _n(4.7):C1)}
[junit4] 2> 61946 T161 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61951 T161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_m,generation=22}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_n,generation=23}
[junit4] 2> 61952 T161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 23
[junit4] 2> 61953 T161 oass.SolrIndexSearcher.<init> Opening Searcher@6f1e6f1e[collection1] main
[junit4] 2> 61954 T161 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61954 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6f1e6f1e[collection1] main{StandardDirectoryReader(segments_n:88:nrt _n(4.7):C1 _o(4.7):C3/2:delGen=2)}
[junit4] 2> 61955 T163 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61956 T163 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 61957 T163 oass.SolrIndexSearcher.<init> Opening Searcher@69816981[collection1] main
[junit4] 2> 61958 T163 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61958 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@69816981[collection1] main{StandardDirectoryReader(segments_n:88:nrt _n(4.7):C1 _o(4.7):C3/2:delGen=2)}
[junit4] 2> 61958 T162 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61971 T162 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_n,generation=23}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_o,generation=24}
[junit4] 2> 61972 T162 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 24
[junit4] 2> 61976 T162 oass.SolrIndexSearcher.<init> Opening Searcher@58425842[collection1] main
[junit4] 2> 61977 T162 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61977 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@58425842[collection1] main{StandardDirectoryReader(segments_o:94:nrt _n(4.7):C1 _o(4.7):C3/2:delGen=2 _q(4.7):C1)}
[junit4] 2> 61977 T161 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61979 T161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_o,generation=24}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_p,generation=25}
[junit4] 2> 61980 T161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 25
[junit4] 2> 61984 T161 oass.SolrIndexSearcher.<init> Opening Searcher@25712571[collection1] main
[junit4] 2> 61985 T161 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61986 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@25712571[collection1] main{StandardDirectoryReader(segments_p:98:nrt _n(4.7):C1 _r(4.7):C1)}
[junit4] 2> 61986 T163 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61988 T163 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_p,generation=25}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_q,generation=26}
[junit4] 2> 61988 T163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 26
[junit4] 2> 61991 T163 oass.SolrIndexSearcher.<init> Opening Searcher@72727272[collection1] main
[junit4] 2> 61992 T163 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61992 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72727272[collection1] main{StandardDirectoryReader(segments_q:100:nrt _n(4.7):C1 _r(4.7):C1 _s(4.7):C1)}
[junit4] 2> 61992 T162 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61995 T162 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_q,generation=26}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_r,generation=27}
[junit4] 2> 61995 T162 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 27
[junit4] 2> 61999 T162 oass.SolrIndexSearcher.<init> Opening Searcher@350f350f[collection1] main
[junit4] 2> 62000 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@350f350f[collection1] main{StandardDirectoryReader(segments_r:104:nrt _r(4.7):C1 _t(4.7):C1)}
[junit4] 2> 62001 T162 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62002 T161 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62003 T161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_r,generation=27}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_s,generation=28}
[junit4] 2> 62003 T161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 28
[junit4] 2> 62008 T161 oass.SolrIndexSearcher.<init> Opening Searcher@533f533f[collection1] main
[junit4] 2> 62009 T161 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62009 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@533f533f[collection1] main{StandardDirectoryReader(segments_s:108:nrt _u(4.7):C1)}
[junit4] 2> 62010 T163 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62011 T163 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_s,generation=28}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_t,generation=29}
[junit4] 2> 62012 T163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 29
[junit4] 2> 62012 T163 oass.SolrIndexSearcher.<init> Opening Searcher@2bd22bd2[collection1] main
[junit4] 2> 62013 T163 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62013 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2bd22bd2[collection1] main{StandardDirectoryReader(segments_s:108:nrt _u(4.7):C1)}
[junit4] 2> 62014 T162 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62015 T162 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 62015 T162 oass.SolrIndexSearcher.<init> Opening Searcher@5c905c90[collection1] main
[junit4] 2> 62016 T162 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62016 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c905c90[collection1] main{StandardDirectoryReader(segments_s:108:nrt _u(4.7):C1)}
[junit4] 2> ASYNC NEW_CORE C1339 name=collection1 org.apache.solr.core.SolrCore@4db04db
[junit4] 2> 62220 T150 C1339 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62221 T150 C1339 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 62222 T150 C1339 oass.SolrIndexSearcher.<init> Opening Searcher@5d765d76[collection1] main
[junit4] 2> 62223 T150 C1339 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62223 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5d765d76[collection1] main{StandardDirectoryReader(segments_s:108:nrt _u(4.7):C1)}
[junit4] 2> 62224 T150 C1339 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 207
[junit4] 2> 62312 T150 oas.SolrTestCaseJ4.tearDown ###Ending testMultiThreaded
[junit4] 2> 62323 T150 oas.SolrTestCaseJ4.setUp ###Starting testDupeAllFieldsDetection
[junit4] 2> 62338 T150 C1339 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 62339 T150 C1339 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 15
[junit4] 2> 62341 T150 C1339 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62342 T150 C1339 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_t,generation=29}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_u,generation=30}
[junit4] 2> 62343 T150 C1339 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 30
[junit4] 2> 62345 T150 C1339 oass.SolrIndexSearcher.<init> Opening Searcher@639a639a[collection1] main
[junit4] 2> 62346 T150 C1339 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62346 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@639a639a[collection1] main{StandardDirectoryReader(segments_u:109:nrt)}
[junit4] 2> 62348 T150 C1339 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 7
[junit4] 2> 62387 T150 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62389 T150 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_u,generation=30}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_v,generation=31}
[junit4] 2> 62390 T150 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 31
[junit4] 2> 62392 T150 oass.SolrIndexSearcher.<init> Opening Searcher@74cd74cd[collection1] main
[junit4] 2> 62393 T150 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62393 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@74cd74cd[collection1] main{StandardDirectoryReader(segments_v:111:nrt _v(4.7):C3)}
[junit4] 2> 62395 T150 oas.SolrTestCaseJ4.tearDown ###Ending testDupeAllFieldsDetection
[junit4] 2> 62404 T150 oas.SolrTestCaseJ4.setUp ###Starting testNonIndexedSignatureField
[junit4] 2> ASYNC NEW_CORE C1340 name=collection1 org.apache.solr.core.SolrCore@4db04db
[junit4] 2> 62405 T150 C1340 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 62406 T150 C1340 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 62407 T150 C1340 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62408 T150 C1340 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_v,generation=31}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_w,generation=32}
[junit4] 2> 62410 T150 C1340 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 32
[junit4] 2> 62411 T150 C1340 oass.SolrIndexSearcher.<init> Opening Searcher@3f9e3f9e[collection1] main
[junit4] 2> 62412 T150 C1340 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62412 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3f9e3f9e[collection1] main{StandardDirectoryReader(segments_w:112:nrt)}
[junit4] 2> 62413 T150 C1340 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 6
[junit4] 2> 62419 T150 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62421 T150 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_w,generation=32}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_x,generation=33}
[junit4] 2> 62422 T150 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 33
[junit4] 2> 62474 T150 oass.SolrIndexSearcher.<init> Opening Searcher@11761176[collection1] main
[junit4] 2> 62475 T150 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62475 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@11761176[collection1] main{StandardDirectoryReader(segments_x:114:nrt _w(4.7):C2)}
[junit4] 2> 62476 T150 oas.SolrTestCaseJ4.tearDown ###Ending testNonIndexedSignatureField
[junit4] 2> 62489 T150 oas.SolrTestCaseJ4.setUp ###Starting testFailNonIndexedSigWithOverwriteDupes
[junit4] 2> 62490 T150 C1340 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 62491 T150 C1340 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4] 2> 62493 T150 C1340 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62494 T150 C1340 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_x,generation=33}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_y,generation=34}
[junit4] 2> 62495 T150 C1340 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 34
[junit4] 2> 62495 T150 C1340 oass.SolrIndexSearcher.<init> Opening Searcher@43104310[collection1] main
[junit4] 2> 62496 T150 C1340 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62497 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@43104310[collection1] main{StandardDirectoryReader(segments_y:115:nrt)}
[junit4] 2> 62498 T150 C1340 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 5
[junit4] 2> 62500 T150 oas.SolrTestCaseJ4.tearDown ###Ending testFailNonIndexedSigWithOverwriteDupes
[junit4] 2> 62508 T150 oas.SolrTestCaseJ4.setUp ###Starting testNonStringFieldsValues
[junit4] 2> ASYNC NEW_CORE C1341 name=collection1 org.apache.solr.core.SolrCore@4db04db
[junit4] 2> 62515 T150 C1341 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 62515 T150 C1341 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 62517 T150 C1341 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62518 T150 C1341 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_y,generation=34}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_z,generation=35}
[junit4] 2> 62519 T150 C1341 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 35
[junit4] 2> 62520 T150 C1341 oass.SolrIndexSearcher.<init> Opening Searcher@36333633[collection1] main
[junit4] 2> 62521 T150 C1341 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62521 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36333633[collection1] main{StandardDirectoryReader(segments_z:116:nrt)}
[junit4] 2> 62522 T150 C1341 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 5
[junit4] 2> 62528 T150 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 62579 T150 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62581 T150 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_z,generation=35}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_10,generation=36}
[junit4] 2> 62581 T150 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 36
[junit4] 2> 62583 T150 oass.SolrIndexSearcher.<init> Opening Searcher@31543154[collection1] main
[junit4] 2> 62584 T150 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62584 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@31543154[collection1] main{StandardDirectoryReader(segments_10:118:nrt _x(4.7):C5/1:delGen=1)}
[junit4] 2> 62585 T150 oas.SolrTestCaseJ4.tearDown ###Ending testNonStringFieldsValues
[junit4] 2> 62593 T150 oas.SolrTestCaseJ4.setUp ###Starting testDupeDetection
[junit4] 2> 62594 T150 C1341 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 62595 T150 C1341 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 62597 T150 C1341 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62598 T150 C1341 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_10,generation=36}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_11,generation=37}
[junit4] 2> 62599 T150 C1341 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 37
[junit4] 2> 62600 T150 C1341 oass.SolrIndexSearcher.<init> Opening Searcher@5dbd5dbd[collection1] main
[junit4] 2> 62601 T150 C1341 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62601 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5dbd5dbd[collection1] main{StandardDirectoryReader(segments_11:119:nrt)}
[junit4] 2> 62603 T150 C1341 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 6
[junit4] 2> 62608 T150 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62611 T150 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_11,generation=37}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_12,generation=38}
[junit4] 2> 62612 T150 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 38
[junit4] 2> 62613 T150 oass.SolrIndexSearcher.<init> Opening Searcher@50d850d8[collection1] main
[junit4] 2> 62614 T150 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62614 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@50d850d8[collection1] main{StandardDirectoryReader(segments_12:121:nrt _y(4.7):C2)}
[junit4] 2> 62618 T150 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 62622 T150 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_12,generation=38}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@56c256c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71c971c9)),segFN=segments_13,generation=39}
[junit4] 2> 62623 T150 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 39
[junit4] 2> 62624 T150 oass.SolrIndexSearcher.<init> Opening Searcher@66cb66cb[collection1] main
[junit4] 2> 62625 T150 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 62625 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@66cb66cb[collection1] main{StandardDirectoryReader(segments_13:124:nrt _y(4.7):C2/1:delGen=1 _z(4.7):C1)}
[junit4] 2> 62626 T150 oas.SolrTestCaseJ4.tearDown ###Ending testDupeDetection
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SignatureUpdateProcessorFactoryTest -Dtests.method=testDupeDetection -Dtests.seed=F7F988A7583FB650 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_UY -Dtests.timezone=Asia/Magadan -Dtests.file.encoding=UTF-8
[junit4] FAILURE 0.05s J1 | SignatureUpdateProcessorFactoryTest.testDupeDetection <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<1> but was:<2>
[junit4] > at __randomizedtesting.SeedInfo.seed([F7F988A7583FB650:ACC9736F5B78152C]:0)
[junit4] > at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.checkNumDocs(SignatureUpdateProcessorFactoryTest.java:71)
[junit4] > at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testDupeDetection(SignatureUpdateProcessorFactoryTest.java:119)
[junit4] > at java.lang.Thread.run(Thread.java:738)
[junit4] 2> 62645 T150 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 62645 T150 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=134940683
[junit4] 2> 62646 T150 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@4db04db
[junit4] 2> 62658 T150 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=42,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=253,cumulative_deletesById=0,cumulative_deletesByQuery=6,cumulative_errors=0}
[junit4] 2> 62659 T150 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 62660 T150 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 62661 T150 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 62666 T150 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 62667 T150 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 62668 T150 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822;done=false>>]
[junit4] 2> 62669 T150 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822
[junit4] 2> 62670 T150 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822/index;done=false>>]
[junit4] 2> 62670 T150 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392313852822/index
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=es_UY, timezone=Asia/Magadan
[junit4] 2> NOTE: Linux 3.8.0-35-generic x86/IBM Corporation 1.6.0 (32-bit)/cpus=8,threads=1,free=9092344,total=29919232
[junit4] 2> NOTE: All tests run in this JVM: [OpenCloseCoreStressTest, StatsComponentTest, PrimUtilsTest, TestFuzzyAnalyzedSuggestions, TestFastOutputStream, SimplePostToolTest, AddSchemaFieldsUpdateProcessorFactoryTest, SpellCheckComponentTest, TestCollapseQParserPlugin, SignatureUpdateProcessorFactoryTest]
[junit4] Completed on J1 in 3.15s, 6 tests, 1 failure <<< FAILURES!
[...truncated 551 lines...]
[junit4] Suite: org.apache.solr.handler.component.TermVectorComponentDistributedTest
[junit4] 2> 1119388 T4092 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 1119391 T4092 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 1119394 T4092 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1119397 T4092 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54168
[junit4] 2> 1119398 T4092 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1119399 T4092 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1119400 T4092 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr
[junit4] 2> 1119401 T4092 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/'
[junit4] 2> 1119420 T4092 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/solr.xml
[junit4] 2> 1119478 T4092 oasc.CoreContainer.<init> New CoreContainer 468524013
[junit4] 2> 1119478 T4092 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/]
[junit4] 2> 1119480 T4092 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1119481 T4092 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1119482 T4092 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1119483 T4092 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1119483 T4092 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1119484 T4092 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1119485 T4092 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1119486 T4092 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1119486 T4092 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1119492 T4092 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1119492 T4092 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1119493 T4092 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1119498 T4102 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1
[junit4] 2> 1119499 T4102 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/'
[junit4] 2> 1119500 T4102 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 1119501 T4102 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 1119546 T4102 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 1119602 T4102 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1119604 T4102 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1119610 T4102 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1120030 T4102 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1120031 T4102 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1120031 T410
[...truncated too long message...]
2> 1402412 T4267 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1402413 T4267 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1402415 T4267 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1402416 T4267 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 1402418 T4267 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1402419 T4267 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard1/data/index;done=false>>]
[junit4] 2> 1402420 T4267 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard1/data/index
[junit4] 2> 1402422 T4267 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard1/data [CachedDir<<refCount=0;path=./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard1/data;done=false>>]
[junit4] 2> 1402423 T4267 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard1/data
[junit4] 2> 1402427 T4267 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/vck/eo,null}
[junit4] 2> 1402500 T4267 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=99026407
[junit4] 2> 1402501 T4267 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@2c712c71
[junit4] 2> 1402517 T4267 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=3,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4] 2> 1402518 T4267 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1402519 T4267 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1402520 T4267 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1402522 T4267 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 1402522 T4267 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1402523 T4267 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard2/data [CachedDir<<refCount=0;path=./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard2/data;done=false>>]
[junit4] 2> 1402524 T4267 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard2/data
[junit4] 2> 1402525 T4267 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard2/data/index [CachedDir<<refCount=0;path=./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard2/data/index;done=false>>]
[junit4] 2> 1402526 T4267 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.component.DistributedQueryElevationComponentTest-1392315193230/shard2/data/index
[junit4] 2> 1402527 T4267 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/vck/eo,null}
[junit4] 2> 1402580 T4267 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=DistributedQueryElevationComponentTest -Dtests.method=testDistribSearch -Dtests.seed=F7F988A7583FB650 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=el_GR_PREEURO -Dtests.timezone=Africa/Monrovia -Dtests.file.encoding=UTF-8
[junit4] FAILURE 2.53s J0 | DistributedQueryElevationComponentTest.testDistribSearch <<<
[junit4] > Throwable #1: junit.framework.AssertionFailedError: .responseHeader.params.sort!=fl (unordered or missing)
[junit4] > at __randomizedtesting.SeedInfo.seed([F7F988A7583FB650:761F06BF2F60D66C]:0)
[junit4] > at junit.framework.Assert.fail(Assert.java:50)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.compareSolrResponses(BaseDistributedSearchTestCase.java:840)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.compareResponses(BaseDistributedSearchTestCase.java:859)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:562)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:542)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:521)
[junit4] > at org.apache.solr.handler.component.DistributedQueryElevationComponentTest.doTest(DistributedQueryElevationComponentTest.java:81)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
[junit4] > at java.lang.Thread.run(Thread.java:738)
[junit4] 2> 1402601 T4267 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=el_GR_PREEURO, timezone=Africa/Monrovia
[junit4] 2> NOTE: Linux 3.8.0-35-generic x86/IBM Corporation 1.6.0 (32-bit)/cpus=8,threads=1,free=24310016,total=42661888
[junit4] 2> NOTE: All tests run in this JVM: [ZkControllerTest, CoreAdminHandlerTest, StatelessScriptUpdateProcessorFactoryTest, DistributedDebugComponentTest, TestSuggestSpellingConverter, CircularListTest, URLClassifyProcessorTest, DocumentBuilderTest, TestReplicationHandler, DocValuesMissingTest, UpdateParamsTest, ReturnFieldsTest, TestLMJelinekMercerSimilarityFactory, BadComponentTest, HdfsBasicDistributedZk2Test, TestDocumentBuilder, DistributedTermsComponentTest, HdfsChaosMonkeySafeLeaderTest, SliceStateUpdateTest, TestSerializedLuceneMatchVersion, TestPseudoReturnFields, MoreLikeThisHandlerTest, TermsComponentTest, EnumFieldTest, TestInitQParser, SolrInfoMBeanTest, SystemInfoHandlerTest, AnalysisErrorHandlingTest, ShowFileRequestHandlerTest, TestLuceneMatchVersion, BinaryUpdateRequestHandlerTest, TestSurroundQueryParser, TestReversedWildcardFilterFactory, TestDocSet, OverseerTest, AliasIntegrationTest, BasicDistributedZkTest, DateMathParserTest, TestRemoteStreaming, TermVectorComponentTest, HdfsBasicDistributedZkTest, CachingDirectoryFactoryTest, ResponseLogComponentTest, TestCoreContainer, SuggesterFSTTest, ClusterStateUpdateTest, QueryElevationComponentTest, TestCursorMarkWithoutUniqueKey, TestLMDirichletSimilarityFactory, HdfsLockFactoryTest, SpatialFilterTest, TestQueryUtils, TestConfig, QueryResultKeyTest, HdfsSyncSliceTest, BlockDirectoryTest, TestAnalyzeInfixSuggestions, CoreMergeIndexesAdminHandlerTest, EchoParamsTest, DocValuesTest, IndexSchemaTest, TestSystemIdResolver, SuggesterTest, TestFieldTypeCollectionResource, ExternalFileFieldSortTest, TestNonNRTOpen, TestSchemaNameResource, TestCloudManagedSchemaAddField, TestSolrQueryParser, CacheHeaderTest, HdfsRecoveryZkTest, TestLRUCache, TestOverriddenPrefixQueryForCustomFieldType, TestCollationKeyRangeQueries, LegacyHTMLStripCharFilterTest, DistributedSuggestComponentTest, DOMUtilTest, TestImplicitCoreProperties, TestSearchPerf, DistributedSpellCheckComponentTest, TestPostingsSolrHighlighter, TestSort, SampleTest, FastVectorHighlighterTest, SoftAutoCommitTest, SolrIndexSplitterTest, RecoveryZkTest, LeaderElectionTest, UnloadDistributedZkTest, SyncSliceTest, ShardRoutingTest, TestRandomFaceting, TestRandomDVFaceting, TestRecovery, TestStressReorder, TestJoin, HardAutoCommitTest, TestRangeQuery, SimpleFacetsTest, SolrCoreTest, TestGroupingSearch, OverseerCollectionProcessorTest, TestIndexSearcher, DistributedQueryElevationComponentTest]
[junit4] Completed on J0 in 2.59s, 1 test, 1 failure <<< FAILURES!
[...truncated 450 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:452: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1308: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:941: There were test failures: 362 suites, 1562 tests, 3 failures, 35 ignored (7 assumptions)
Total time: 62 minutes 17 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk6 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure