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/07/04 21:14:18 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.8.0) - Build # 1690
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1690/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch
Error Message:
No registered leader was found after waiting for 30000ms , collection: collection1 slice: shard1
Stack Trace:
org.apache.solr.common.SolrException: No registered leader was found after waiting for 30000ms , collection: collection1 slice: shard1
at __randomizedtesting.SeedInfo.seed([8FBF0BB5D9E1B426:E5985ADAEBED41A]:0)
at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:567)
at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:203)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
at sun.reflect.GeneratedMethodAccessor36.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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.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:65)
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:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:365)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11766 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/init-core-data-001
[junit4] 2> 3049950 T11620 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /s_wpv/
[junit4] 2> 3049956 T11620 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 3049958 T11620 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 3049961 T11621 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 3050062 T11620 oasc.ZkTestServer.run start zk server on port:52623
[junit4] 2> 3050064 T11620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3050086 T11627 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f68a642 name:ZooKeeperConnection Watcher:127.0.0.1:52623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3050087 T11620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3050088 T11620 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 3050109 T11622 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14702bdea7f0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 3050117 T11620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3050123 T11629 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28a0ab82 name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3050125 T11620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3050125 T11620 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 3050134 T11620 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 3050140 T11620 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 3050147 T11620 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 3050153 T11620 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 3050154 T11620 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 3050173 T11620 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 3050173 T11620 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 3050182 T11620 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 3050184 T11620 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 3050191 T11620 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 3050192 T11620 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 3050199 T11620 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 3050200 T11620 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 3050224 T11620 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 3050225 T11620 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 3050234 T11620 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 3050235 T11620 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 3050243 T11620 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 3050244 T11620 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 3050251 T11620 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 3050258 T11620 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 3050273 T11620 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 3050274 T11620 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 3050281 T11620 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 3050290 T11620 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 3052531 T11620 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 3052542 T11620 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52626
[junit4] 2> 3052543 T11620 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 3052543 T11620 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 3052544 T11620 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-002
[junit4] 2> 3052544 T11620 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-002/'
[junit4] 2> 3052598 T11620 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-002/solr.xml
[junit4] 2> 3052642 T11620 oasc.CoreContainer.<init> New CoreContainer 1039665597
[junit4] 2> 3052643 T11620 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-002/]
[junit4] 2> 3052644 T11620 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 3052645 T11620 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 3052645 T11620 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 3052646 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 3052647 T11620 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 3052647 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 3052648 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 3052648 T11620 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 3052649 T11620 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 3052650 T11620 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 3052651 T11620 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 3052652 T11620 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 3052653 T11620 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52623/solr
[junit4] 2> 3052654 T11620 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 3052657 T11620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3052661 T11640 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45144989 name:ZooKeeperConnection Watcher:127.0.0.1:52623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3052662 T11620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3052668 T11620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3052674 T11642 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60dc08c3 name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3052674 T11620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3052679 T11620 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 3052695 T11620 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 3052705 T11620 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 3052714 T11620 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 3052726 T11620 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 3052736 T11620 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 3052742 T11620 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52626_s_wpv
[junit4] 2> 3052745 T11620 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52626_s_wpv
[junit4] 2> 3052756 T11620 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 3052764 T11620 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 3052778 T11620 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52626_s_wpv
[junit4] 2> 3052778 T11620 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 3052784 T11620 oasc.Overseer.start Overseer (id=92045332090650627-127.0.0.1:52626_s_wpv-n_0000000000) starting
[junit4] 2> 3052795 T11620 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 3052826 T11644 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 3052827 T11620 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 3052835 T11620 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 3052840 T11620 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 3052849 T11643 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 3052859 T11645 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 3052859 T11645 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3052862 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3052862 T11645 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 3052866 T11643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3052868 T11643 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:52626/s_wpv",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52626_s_wpv",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 3052869 T11643 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 3052869 T11643 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 3052879 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3052881 T11642 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> 3053864 T11645 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 3053865 T11645 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 3053867 T11645 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 3053867 T11645 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 3053870 T11645 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3053871 T11645 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-002/collection1/'
[junit4] 2> 3053873 T11645 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 3053874 T11645 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 3053875 T11645 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 3053952 T11645 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 3053968 T11645 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 3053978 T11645 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 3053989 T11645 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 3054165 T11645 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 3054166 T11645 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3054170 T11645 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3054178 T11645 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3054265 T11645 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 3054266 T11645 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 3054269 T11645 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-002/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/control/data/
[junit4] 2> 3054272 T11645 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@42e45bac
[junit4] 2> 3054276 T11645 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/control/data
[junit4] 2> 3054277 T11645 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/control/data/index/
[junit4] 2> 3054279 T11645 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 3054282 T11645 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/control/data/index
[junit4] 2> 3054287 T11645 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2862759950848359]
[junit4] 2> 3054296 T11645 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 3054296 T11645 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3054311 T11645 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 3054312 T11645 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 3054313 T11645 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 3054313 T11645 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 3054314 T11645 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 3054314 T11645 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 3054317 T11645 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3054321 T11645 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3054322 T11645 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 3054323 T11645 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 3054324 T11645 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 3054324 T11645 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 3054325 T11645 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 3054325 T11645 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3054326 T11645 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 3054326 T11645 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 3054327 T11645 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 3054338 T11645 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3054342 T11645 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3054342 T11645 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3054343 T11645 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=28, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.14823505479983654]
[junit4] 2> 3054347 T11645 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 3054347 T11645 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3054348 T11645 oass.SolrIndexSearcher.<init> Opening Searcher@5048de05[collection1] main
[junit4] 2> 3054349 T11645 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 3054353 T11645 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3054354 T11645 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 3054355 T11645 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 3054356 T11645 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 3054356 T11645 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3054358 T11645 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 3054358 T11645 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3054361 T11645 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json
[junit4] 2> 3054368 T11645 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json
[junit4] 2> 3054368 T11645 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3054369 T11645 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 3054372 T11646 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5048de05[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 3054376 T11645 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 3054379 T11649 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52626/s_wpv collection:control_collection shard:shard1
[junit4] 2> 3054380 T11620 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 3054381 T11620 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 3054384 T11620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3054389 T11651 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@784aad24 name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3054389 T11649 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 3054390 T11620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3054395 T11620 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 3054407 T11620 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 3054441 T11649 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 3054476 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3054486 T11649 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 3054490 T11649 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2277 name=collection1 org.apache.solr.core.SolrCore@5428e557 url=http://127.0.0.1:52626/s_wpv/collection1 node=127.0.0.1:52626_s_wpv C2277_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:52626/s_wpv, core=collection1, node_name=127.0.0.1:52626_s_wpv}
[junit4] 2> 3054490 T11649 C2277 P52626 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52626/s_wpv/collection1/
[junit4] 2> 3054491 T11649 C2277 P52626 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 3054491 T11649 C2277 P52626 oasc.SyncStrategy.syncToMe http://127.0.0.1:52626/s_wpv/collection1/ has no replicas
[junit4] 2> 3054491 T11649 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52626/s_wpv/collection1/ shard1
[junit4] 2> 3054491 T11649 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 3054494 T11643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3054528 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3054532 T11642 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> 3054532 T11651 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> 3054553 T11643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3054563 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3054669 T11651 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> 3054669 T11642 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> 3054701 T11649 oasc.ZkController.register We are http://127.0.0.1:52626/s_wpv/collection1/ and leader is http://127.0.0.1:52626/s_wpv/collection1/
[junit4] 2> 3054702 T11649 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52626/s_wpv
[junit4] 2> 3054703 T11649 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 3054703 T11649 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 3054704 T11649 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3054708 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3054709 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3054709 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3054710 T11649 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3054723 T11643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3054727 T11643 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:52626/s_wpv",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52626_s_wpv",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 3054739 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3054854 T11642 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> 3054858 T11651 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> 3057024 T11620 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 3057025 T11620 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 3057034 T11620 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52630
[junit4] 2> 3057034 T11620 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 3057035 T11620 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 3057036 T11620 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-003
[junit4] 2> 3057036 T11620 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-003/'
[junit4] 2> 3057107 T11620 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-003/solr.xml
[junit4] 2> 3057132 T11620 oasc.CoreContainer.<init> New CoreContainer 1791722321
[junit4] 2> 3057132 T11620 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-003/]
[junit4] 2> 3057133 T11620 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 3057134 T11620 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 3057134 T11620 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 3057135 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 3057136 T11620 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 3057136 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 3057137 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 3057138 T11620 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 3057139 T11620 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 3057140 T11620 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 3057140 T11620 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 3057141 T11620 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 3057141 T11620 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52623/solr
[junit4] 2> 3057143 T11620 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 3057146 T11620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3057152 T11662 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39f63284 name:ZooKeeperConnection Watcher:127.0.0.1:52623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3057152 T11620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3057161 T11620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3057164 T11664 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26c1edd8 name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3057164 T11620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3057186 T11620 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 3058200 T11620 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52630_s_wpv
[junit4] 2> 3058203 T11620 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52630_s_wpv
[junit4] 2> 3058228 T11665 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 3058228 T11665 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3058230 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3058231 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3058231 T11665 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 3058231 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3058236 T11643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3058238 T11643 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52630/s_wpv",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52630_s_wpv",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 3058239 T11643 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 3058239 T11643 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 3058247 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3058249 T11651 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> 3058251 T11642 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> 3058250 T11664 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> 3059233 T11665 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 3059234 T11665 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 3059237 T11665 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 3059238 T11665 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 3059240 T11665 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3059241 T11665 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-003/collection1/'
[junit4] 2> 3059242 T11665 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 3059243 T11665 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 3059244 T11665 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 3059302 T11665 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 3059316 T11665 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 3059321 T11665 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 3059328 T11665 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 3059431 T11665 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 3059431 T11665 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3059433 T11665 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3059440 T11665 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3059503 T11665 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 3059503 T11665 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 3059503 T11665 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-003/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty1/
[junit4] 2> 3059504 T11665 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@42e45bac
[junit4] 2> 3059505 T11665 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty1
[junit4] 2> 3059505 T11665 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty1/index/
[junit4] 2> 3059506 T11665 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 3059507 T11665 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty1/index
[junit4] 2> 3059507 T11665 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2862759950848359]
[junit4] 2> 3059512 T11665 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 3059513 T11665 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3059517 T11665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 3059517 T11665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 3059518 T11665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 3059518 T11665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 3059518 T11665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 3059519 T11665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 3059519 T11665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3059519 T11665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3059520 T11665 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 3059520 T11665 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 3059521 T11665 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 3059521 T11665 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 3059521 T11665 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 3059522 T11665 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3059522 T11665 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 3059523 T11665 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 3059524 T11665 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 3059531 T11665 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3059533 T11665 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3059533 T11665 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3059534 T11665 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=28, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.14823505479983654]
[junit4] 2> 3059535 T11665 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 3059536 T11665 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3059536 T11665 oass.SolrIndexSearcher.<init> Opening Searcher@5f58e185[collection1] main
[junit4] 2> 3059536 T11665 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 3059540 T11665 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3059540 T11665 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 3059542 T11665 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 3059542 T11665 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 3059543 T11665 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3059546 T11665 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 3059546 T11665 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3059546 T11665 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 3059547 T11665 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 3059553 T11666 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5f58e185[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 3059554 T11665 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 3059557 T11669 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52630/s_wpv collection:collection1 shard:shard2
[junit4] 2> 3059557 T11620 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 3059558 T11620 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 3059559 T11669 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 3059577 T11669 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 3059582 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3059584 T11669 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 3059585 T11669 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2278 name=collection1 org.apache.solr.core.SolrCore@7b2d9844 url=http://127.0.0.1:52630/s_wpv/collection1 node=127.0.0.1:52630_s_wpv C2278_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:52630/s_wpv, core=collection1, node_name=127.0.0.1:52630_s_wpv}
[junit4] 2> 3059586 T11669 C2278 P52630 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52630/s_wpv/collection1/
[junit4] 2> 3059587 T11669 C2278 P52630 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 3059587 T11669 C2278 P52630 oasc.SyncStrategy.syncToMe http://127.0.0.1:52630/s_wpv/collection1/ has no replicas
[junit4] 2> 3059587 T11669 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52630/s_wpv/collection1/ shard2
[junit4] 2> 3059587 T11669 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 3059597 T11643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3059612 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3059635 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3059740 T11651 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> 3059742 T11664 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> 3059744 T11642 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> 3059763 T11669 oasc.ZkController.register We are http://127.0.0.1:52630/s_wpv/collection1/ and leader is http://127.0.0.1:52630/s_wpv/collection1/
[junit4] 2> 3059764 T11669 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52630/s_wpv
[junit4] 2> 3059765 T11669 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 3059765 T11669 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 3059766 T11669 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3059780 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3059781 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3059782 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3059782 T11669 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3059790 T11643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3059791 T11643 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:52630/s_wpv",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52630_s_wpv",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 3059803 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3059910 T11651 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> 3059910 T11642 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> 3059910 T11664 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> 3062035 T11620 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 3062037 T11620 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 3062045 T11620 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52633
[junit4] 2> 3062046 T11620 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 3062046 T11620 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 3062048 T11620 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-004
[junit4] 2> 3062048 T11620 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-004/'
[junit4] 2> 3062106 T11620 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-004/solr.xml
[junit4] 2> 3062121 T11620 oasc.CoreContainer.<init> New CoreContainer 1659242276
[junit4] 2> 3062122 T11620 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-004/]
[junit4] 2> 3062123 T11620 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 3062123 T11620 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 3062123 T11620 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 3062124 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 3062124 T11620 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 3062124 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 3062125 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 3062125 T11620 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 3062125 T11620 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 3062126 T11620 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 3062126 T11620 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 3062127 T11620 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 3062128 T11620 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52623/solr
[junit4] 2> 3062128 T11620 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 3062131 T11620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3062138 T11680 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35fbf9a1 name:ZooKeeperConnection Watcher:127.0.0.1:52623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3062138 T11620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3062146 T11620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3062148 T11682 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@65115f37 name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3062149 T11620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3062175 T11620 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 3063192 T11620 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52633_s_wpv
[junit4] 2> 3063195 T11620 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52633_s_wpv
[junit4] 2> 3063218 T11683 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 3063218 T11683 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3063220 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3063221 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3063221 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3063220 T11683 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 3063226 T11643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3063227 T11643 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52633/s_wpv",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52633_s_wpv",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 3063227 T11643 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 3063228 T11643 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 3063235 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3063238 T11651 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> 3063238 T11682 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> 3063238 T11642 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> 3063238 T11664 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> 3064223 T11683 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 3064224 T11683 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 3064228 T11683 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 3064228 T11683 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 3064234 T11683 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3064235 T11683 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-004/collection1/'
[junit4] 2> 3064236 T11683 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 3064237 T11683 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 3064238 T11683 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 3064306 T11683 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 3064320 T11683 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 3064325 T11683 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 3064334 T11683 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 3064500 T11683 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 3064502 T11683 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 3064503 T11683 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3064514 T11683 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3064594 T11683 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 3064594 T11683 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 3064595 T11683 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-004/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty2/
[junit4] 2> 3064595 T11683 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@42e45bac
[junit4] 2> 3064597 T11683 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty2
[junit4] 2> 3064599 T11683 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty2/index/
[junit4] 2> 3064600 T11683 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 3064601 T11683 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty2/index
[junit4] 2> 3064605 T11683 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2862759950848359]
[junit4] 2> 3064611 T11683 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 3064611 T11683 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3064617 T11683 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 3064619 T11683 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 3064625 T11683 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 3064626 T11683 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 3064627 T11683 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 3064627 T11683 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 3064635 T11683 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3064635 T11683 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 3064636 T11683 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 3064637 T11683 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 3064638 T11683 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 3064638 T11683 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 3064638 T11683 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 3064642 T11683 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 3064643 T11683 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 3064645 T11683 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 3064645 T11683 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 3064654 T11683 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 3064658 T11683 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 3064659 T11683 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 3064660 T11683 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=28, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.14823505479983654]
[junit4] 2> 3064662 T11683 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 3064662 T11683 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 3064663 T11683 oass.SolrIndexSearcher.<init> Opening Searcher@66813f59[collection1] main
[junit4] 2> 3064663 T11683 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 3064672 T11683 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 3064672 T11683 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 3064679 T11683 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 3064679 T11683 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 3064679 T11683 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3064681 T11683 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 3064681 T11683 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 3064682 T11683 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 3064682 T11683 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 3064687 T11684 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@66813f59[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 3064690 T11683 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 3064692 T11687 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52633/s_wpv collection:collection1 shard:shard1
[junit4] 2> 3064695 T11620 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 3064696 T11620 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 3064706 T11687 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 3064775 T11687 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 3064787 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3064790 T11687 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 3064790 T11687 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2279 name=collection1 org.apache.solr.core.SolrCore@77e5daa2 url=http://127.0.0.1:52633/s_wpv/collection1 node=127.0.0.1:52633_s_wpv C2279_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:52633/s_wpv, core=collection1, node_name=127.0.0.1:52633_s_wpv}
[junit4] 2> 3064790 T11687 C2279 P52633 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52633/s_wpv/collection1/
[junit4] 2> 3064791 T11687 C2279 P52633 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 3064791 T11687 C2279 P52633 oasc.SyncStrategy.syncToMe http://127.0.0.1:52633/s_wpv/collection1/ has no replicas
[junit4] 2> 3064791 T11687 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52633/s_wpv/collection1/ shard1
[junit4] 2> 3064791 T11687 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 3064794 T11643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3064813 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3064815 T11642 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> 3064815 T11664 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> 3064816 T11651 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> 3064819 T11682 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> 3064843 T11643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3064852 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3064965 T11664 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> 3064966 T11642 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> 3064965 T11651 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> 3064968 T11682 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> 3064999 T11687 oasc.ZkController.register We are http://127.0.0.1:52633/s_wpv/collection1/ and leader is http://127.0.0.1:52633/s_wpv/collection1/
[junit4] 2> 3064999 T11687 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52633/s_wpv
[junit4] 2> 3064999 T11687 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 3064999 T11687 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 3065000 T11687 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 3065008 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3065009 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3065009 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3065011 T11687 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3065015 T11643 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 3065018 T11643 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:52633/s_wpv",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52633_s_wpv",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 3065030 T11642 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 3065138 T11664 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> 3065139 T11642 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> 3065140 T11651 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> 3065138 T11682 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> 3067020 T11620 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 3067021 T11620 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 3067029 T11620 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52636
[junit4] 2> 3067030 T11620 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 3067031 T11620 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 3067031 T11620 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-005
[junit4] 2> 3067031 T11620 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-005/'
[junit4] 2> 3067109 T11620 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-005/solr.xml
[junit4] 2> 3067125 T11620 oasc.CoreContainer.<init> New CoreContainer 540660426
[junit4] 2> 3067125 T11620 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ChaosMonkeyNothingIsSafeTest-8FBF0BB5D9E1B426-001/tempDir-005/]
[junit4] 2> 3067127 T11620 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 3067127 T11620 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 3067127 T11620 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 3067127 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 3067128 T11620 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 3067128 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 3067129 T11620 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 3067129 T11620 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 3067129 T11620 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 3067130 T11620 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 3067130 T11620 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 3067131 T11620 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 3067131 T11620 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52623/solr
[junit4] 2> 3067132 T11620 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 3067134 T11620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3067138 T11698 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11a79cb6 name:ZooKeeperConnection Watcher:127.0.0.1:52623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3067138 T11620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3067145 T11620 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 3067148 T11700 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1732bfe0 name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 3067149 T11620 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 3067167 T11620 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 3068176 T11620 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52636_s_wpv
[junit4] 2> 3068181 T11620 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52636_s_wpv
[junit4] 2> 3068207 T11701 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 3068207 T11701 oasc.ZkController.
[...truncated too long message...]
.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 3209295 T11783 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=es_PA, timezone=America/Thule
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_05 (64-bit)/cpus=2,threads=1,free=241366896,total=362283008
[junit4] 2> NOTE: All tests run in this JVM: [CSVRequestHandlerTest, SortByFunctionTest, NumericFieldsTest, BadCopyFieldTest, ParsingFieldUpdateProcessorsTest, SampleTest, TestSuggestSpellingConverter, SolrXmlInZkTest, SolrCoreCheckLockOnStartupTest, AtomicUpdatesTest, AnalyticsMergeStrategyTest, SpellingQueryConverterTest, TestDFRSimilarityFactory, ReplicationFactorTest, DistribCursorPagingTest, TestSolrDeletionPolicy1, TestRealTimeGet, TestComplexPhraseQParserPlugin, SpellPossibilityIteratorTest, TestUtils, TestInfoStreamLogging, DocValuesTest, TestExpandComponent, HighlighterTest, TestSchemaNameResource, SolrIndexSplitterTest, TestConfigSets, TestPostingsSolrHighlighter, TestDistribDocBasedVersion, TestFastLRUCache, CollectionsAPIAsyncDistributedZkTest, HdfsCollectionsAPIDistributedZkTest, PluginInfoTest, HdfsLockFactoryTest, TestConfig, HdfsWriteToMultipleCollectionsTest, BasicZkTest, DirectSolrSpellCheckerTest, TestManagedResourceStorage, TestRTGBase, SimpleFacetsTest, BJQParserTest, TestFieldTypeResource, LegacyHTMLStripCharFilterTest, CoreAdminHandlerTest, AnalyticsQueryTest, ShardRoutingTest, TestSolrXMLSerializer, ConvertedLegacyTest, TestSerializedLuceneMatchVersion, ChaosMonkeySafeLeaderTest, TestModifyConfFiles, URLClassifyProcessorTest, ShardSplitTest, BadIndexSchemaTest, TestDistributedGrouping, TestLazyCores, TestHighlightDedupGrouping, UniqFieldsUpdateProcessorFactoryTest, RankQueryTest, TestSolrJ, HighlighterConfigTest, TestCollapseQParserPlugin, ZkNodePropsTest, HardAutoCommitTest, TestDefaultSimilarityFactory, DateFieldTest, TestRemoteStreaming, TestLFUCache, SynonymTokenizerTest, TestSearchPerf, TestHighFrequencyDictionaryFactory, TestGroupingSearch, MigrateRouteKeyTest, TestLRUCache, CacheHeaderTest, TestSweetSpotSimilarityFactory, TestFileDictionaryLookup, DisMaxRequestHandlerTest, TestCloudManagedSchema, DeleteInactiveReplicaTest, TestRecoveryHdfs, FileUtilsTest, HttpPartitionTest, AnalysisAfterCoreReloadTest, TestStressUserVersions, FieldFacetTest, TestZkChroot, TestIBSimilarityFactory, TestReload, ZkSolrClientTest, CurrencyFieldXmlFileTest, TestReplicationHandlerBackup, TestLMJelinekMercerSimilarityFactory, TestAddFieldRealTimeGet, TestCodecSupport, DistribDocExpirationUpdateProcessorTest, SSLMigrationTest, SyncSliceTest, CursorMarkTest, NotRequiredUniqueKeyTest, StressHdfsTest, TestSearcherReuse, SuggesterWFSTTest, TestMiniSolrCloudCluster, SuggestComponentTest, DateRangeFieldTest, TermVectorComponentTest, AutoCommitTest, TestLMDirichletSimilarityFactory, TestManagedStopFilterFactory, TestRecovery, TestFreeTextSuggestions, TestSolrXml, SuggesterTest, SystemInfoHandlerTest, SolrRequestParserTest, TestValueSourceCache, ModifyConfFileTest, BasicFunctionalityTest, TestJoin, TestFoldingMultitermQuery, TriLevelCompositeIdRoutingTest, OverseerTest, PeerSyncTest, RemoteQueryErrorTest, TestShortCircuitedRequests, TermVectorComponentDistributedTest, EnumFieldTest, NoCacheHeaderTest, QueryFacetTest, TestCollectionAPI, TestCustomSort, ExternalFileFieldSortTest, StandardRequestHandlerTest, UUIDFieldTest, LoggingHandlerTest, SolrIndexConfigTest, SignatureUpdateProcessorFactoryTest, MergeStrategyTest, DistributedQueryComponentOptimizationTest, TestCloudInspectUtil, TestJmxIntegration, DistributedExpandComponentTest, TestQuerySenderListener, AsyncMigrateRouteKeyTest, BlockDirectoryTest, QueryResultKeyTest, TestRandomFaceting, XsltUpdateRequestHandlerTest, JsonLoaderTest, CopyFieldTest, TestSimpleQParserPlugin, DeleteReplicaTest, TestCursorMarkWithoutUniqueKey, TestMultiCoreConfBootstrap, TestMergePolicyConfig, CoreContainerCoreInitFailuresTest, TestNoOpRegenerator, SpatialFilterTest, TestIndexingPerformance, ResourceLoaderTest, DistributedSuggestComponentTest, TestStressReorder, TestClassNameShortening, ChangedSchemaMergeTest, DirectUpdateHandlerTest, TestAnalyzedSuggestions, HdfsRecoveryZkTest, FileBasedSpellCheckerTest, DocValuesMissingTest, TimeZoneUtilsTest, SOLR749Test, BlockCacheTest, TestPartialUpdateDeduplication, TermsComponentTest, TestNonNRTOpen, DOMUtilTest, TestBadConfig, TestPseudoReturnFields, RequiredFieldsTest, TestSolrQueryParserResource, CoreAdminRequestStatusTest, CoreAdminCreateDiscoverTest, ResponseHeaderTest, TestCSVLoader, OverseerStatusTest, TestOrdValues, BasicDistributedZk2Test, TestCharFilters, MBeansHandlerTest, TestSolrCoreProperties, TestRangeQuery, CursorPagingTest, MoreLikeThisHandlerTest, CustomCollectionTest, TestXIncludeConfig, TestSolrIndexConfig, OverseerCollectionProcessorTest, FieldMutatingUpdateProcessorTest, TestCopyFieldCollectionResource, TestDocSet, BasicDistributedZkTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler, ClusterStateUpdateTest, LeaderElectionTest, TestRandomDVFaceting, ZkCLITest, ShardRoutingCustomTest, TestDistributedSearch, TestFaceting, TestHashPartitioner, DistributedSpellCheckComponentTest, ZkControllerTest, TestStressVersions, DistributedTermsComponentTest, TestCoreContainer, TestSolr4Spatial, SolrCoreTest, StatsComponentTest, SpellCheckComponentTest, SolrCmdDistributorTest, QueryElevationComponentTest, TestSort, TestFiltering, TestFunctionQuery, TestIndexSearcher, SoftAutoCommitTest, ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, SimplePostToolTest, TestCoreDiscovery, TestExtendedDismaxParser, SpellCheckCollatorTest, SuggesterFSTTest, SuggesterTSTTest, TestStressLucene, TestTrie, PolyFieldTest, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, TestUpdate, TestAtomicUpdateErrorCases, TestWordDelimiterFilterFactory, QueryEqualityTest, DirectUpdateHandlerOptimizeTest, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, DocValuesMultiTest, DistanceFunctionTest, SolrInfoMBeanTest, DebugComponentTest, IndexBasedSpellCheckerTest, TestSurroundQueryParser, LukeRequestHandlerTest, TestQueryUtils, TestWriterPerf, TestReversedWildcardFilterFactory, DocumentAnalysisRequestHandlerTest, TestQueryTypes, PrimitiveFieldTypeTest, TestOmitPositions, XmlUpdateRequestHandlerTest, RequestHandlersTest, DocumentBuilderTest, PathHierarchyTokenizerFactoryTest, FieldAnalysisRequestHandlerTest, TestSolrQueryParser, TestArbitraryIndexDir, FastVectorHighlighterTest, IndexSchemaRuntimeFieldTest, RegexBoostProcessorTest, SolrPluginUtilsTest, IndexSchemaTest, TestCollationField, ReturnFieldsTest, UpdateRequestProcessorFactoryTest, JSONWriterTest, TestCSVResponseWriter, QueryParsingTest, BinaryUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, PingRequestHandlerTest, TestComponentsName, SearchHandlerTest, TestBinaryResponseWriter, UpdateParamsTest, AlternateDirectoryTest, TestQuerySenderNoQuery, ResponseLogComponentTest, BadComponentTest, TestStressRecovery, TestSolrDeletionPolicy2, MultiTermTest, TestBinaryField, MinimalSchemaTest, TestElisionMultitermQuery, OutputWriterTest, TestFuzzyAnalyzedSuggestions, DirectSolrConnectionTest, TestLuceneMatchVersion, TestPhraseSuggestions, EchoParamsTest, TestPerFieldSimilarity, TestBM25SimilarityFactory, TestFastWriter, TestJmxMonitoredMap, TestFastOutputStream, ScriptEngineTest, OpenExchangeRatesOrgProviderTest, DateMathParserTest, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed in 159.47s, 1 test, 1 error <<< FAILURES!
[...truncated 272 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1298: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:922: There were test failures: 415 suites, 1704 tests, 1 error, 43 ignored (16 assumptions)
Total time: 104 minutes 20 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.8.0) - Build # 1691
- Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1691/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseParallelGC
4 tests failed.
FAILED: org.apache.solr.client.solrj.embedded.SolrExampleEmbeddedTest.testChildDoctransformer
Error Message:
Stack Trace:
java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([EAE765ED855F3E3F:993D7A7709474939]:0)
at org.apache.lucene.search.join.ToChildBlockJoinQuery$ToChildBlockJoinScorer.advance(ToChildBlockJoinQuery.java:286)
at org.apache.lucene.search.FilteredQuery$LeapFrogScorer.advanceToNextCommonDoc(FilteredQuery.java:274)
at org.apache.lucene.search.FilteredQuery$LeapFrogScorer.nextDoc(FilteredQuery.java:286)
at org.apache.lucene.search.Weight$DefaultBulkScorer.scoreAll(Weight.java:192)
at org.apache.lucene.search.Weight$DefaultBulkScorer.score(Weight.java:163)
at org.apache.lucene.search.BulkScorer.score(BulkScorer.java:35)
at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:614)
at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:289)
at org.apache.solr.search.SolrIndexSearcher.buildAndRunCollectorChain(SolrIndexSearcher.java:224)
at org.apache.solr.search.SolrIndexSearcher.getDocListNC(SolrIndexSearcher.java:1631)
at org.apache.solr.search.SolrIndexSearcher.getDocListC(SolrIndexSearcher.java:1454)
at org.apache.solr.search.SolrIndexSearcher.search(SolrIndexSearcher.java:535)
at org.apache.solr.search.SolrIndexSearcher.getDocList(SolrIndexSearcher.java:1289)
at org.apache.solr.response.transform.ChildDocTransformer.transform(ChildDocTransformerFactory.java:144)
at org.apache.solr.response.BinaryResponseWriter$Resolver.writeResultsBody(BinaryResponseWriter.java:150)
at org.apache.solr.response.BinaryResponseWriter$Resolver.writeResults(BinaryResponseWriter.java:174)
at org.apache.solr.response.BinaryResponseWriter$Resolver.resolve(BinaryResponseWriter.java:87)
at org.apache.solr.common.util.JavaBinCodec.writeVal(JavaBinCodec.java:158)
at org.apache.solr.common.util.JavaBinCodec.writeNamedList(JavaBinCodec.java:148)
at org.apache.solr.common.util.JavaBinCodec.writeKnownType(JavaBinCodec.java:242)
at org.apache.solr.common.util.JavaBinCodec.writeVal(JavaBinCodec.java:153)
at org.apache.solr.common.util.JavaBinCodec.marshal(JavaBinCodec.java:96)
at org.apache.solr.response.BinaryResponseWriter.getParsedResponse(BinaryResponseWriter.java:247)
at org.apache.solr.client.solrj.embedded.EmbeddedSolrServer.getParsedResponse(EmbeddedSolrServer.java:241)
at org.apache.solr.client.solrj.embedded.EmbeddedSolrServer.request(EmbeddedSolrServer.java:213)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.client.solrj.SolrExampleTests.testChildDoctransformer(SolrExampleTests.java:1373)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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.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:65)
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:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:365)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.client.solrj.embedded.SolrExampleJettyTest.testChildDoctransformer
Error Message:
Expected mime type application/octet-stream but got text/html. <html> <head> <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/> <title>Error 500 Server Error</title> </head> <body> <h2>HTTP ERROR: 500</h2> <p>Problem accessing /solr/collection1/select. Reason: <pre> Server Error</pre></p> <hr /><i><small>Powered by Jetty://</small></i> </body> </html>
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Expected mime type application/octet-stream but got text/html. <html>
<head>
<meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
<title>Error 500 Server Error</title>
</head>
<body>
<h2>HTTP ERROR: 500</h2>
<p>Problem accessing /solr/collection1/select. Reason:
<pre> Server Error</pre></p>
<hr /><i><small>Powered by Jetty://</small></i>
</body>
</html>
at __randomizedtesting.SeedInfo.seed([EAE765ED855F3E3F:993D7A7709474939]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:516)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.client.solrj.SolrExampleTests.testChildDoctransformer(SolrExampleTests.java:1373)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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.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:65)
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:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:365)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest.testChildDoctransformer
Error Message:
Expected mime type application/octet-stream but got text/html. <html> <head> <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/> <title>Error 500 Server Error</title> </head> <body> <h2>HTTP ERROR: 500</h2> <p>Problem accessing /solr/collection1/select. Reason: <pre> Server Error</pre></p> <hr /><i><small>Powered by Jetty://</small></i> </body> </html>
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Expected mime type application/octet-stream but got text/html. <html>
<head>
<meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
<title>Error 500 Server Error</title>
</head>
<body>
<h2>HTTP ERROR: 500</h2>
<p>Problem accessing /solr/collection1/select. Reason:
<pre> Server Error</pre></p>
<hr /><i><small>Powered by Jetty://</small></i>
</body>
</html>
at __randomizedtesting.SeedInfo.seed([EAE765ED855F3E3F:993D7A7709474939]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:516)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
at org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer.request(ConcurrentUpdateSolrServer.java:280)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.client.solrj.SolrExampleTests.testChildDoctransformer(SolrExampleTests.java:1373)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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.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:65)
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:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:365)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.client.solrj.embedded.SolrExampleStreamingTest.testChildDoctransformer
Error Message:
java.lang.AssertionError
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([EAE765ED855F3E3F:993D7A7709474939]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:554)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
at org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer.request(ConcurrentUpdateSolrServer.java:280)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.client.solrj.SolrExampleTests.testChildDoctransformer(SolrExampleTests.java:1373)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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.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:65)
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:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:365)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 12291 lines...]
[junit4] Suite: org.apache.solr.client.solrj.embedded.SolrExampleJettyTest
[junit4] 2> SLF4J: Class path contains multiple SLF4J bindings.
[junit4] 2> SLF4J: Found binding in [jar:file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/test-lib/slf4j-log4j12-1.7.6.jar!/org/slf4j/impl/StaticLoggerBinder.class]
[junit4] 2> SLF4J: Found binding in [jar:file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/slf4j-log4j12-1.7.6.jar!/org/slf4j/impl/StaticLoggerBinder.class]
[junit4] 2> SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
[junit4] 2> SLF4J: Actual binding is of type [org.slf4j.impl.Log4jLoggerFactory]
[junit4] 2> log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout.
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/./temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/init-core-data-001
[junit4] 2> 3309 T11 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 3330 T11 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 4095 T11 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 4528 T11 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53580
[junit4] 2> 4832 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 4962 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 4963 T11 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr
[junit4] 2> 4964 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/'
[junit4] 2> 5635 T11 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/solr.xml
[junit4] 2> 5970 T11 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr
[junit4] 2> 6011 T11 oasc.CoreContainer.<init> New CoreContainer 792171065
[junit4] 2> 6019 T11 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/]
[junit4] 2> 6187 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 6188 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 6201 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 6202 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 6204 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 6204 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 6205 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 6206 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 6207 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 6803 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 6809 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 6818 T11 oasc.CoreContainer.load Host Name:
[junit4] 2> 7209 T11 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr
[junit4] 2> 7351 T11 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/
[junit4] 2> 7352 T11 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 7361 T23 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/'
[junit4] 2> 7595 T23 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 7604 T23 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 7606 T23 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 7607 T23 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 7608 T23 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 7608 T23 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 7609 T23 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 7610 T23 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 7611 T23 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/../../../dist).
[junit4] 2> 7687 T23 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
[junit4] 2> 7759 T23 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 8621 T23 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 8709 T23 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 8816 T23 oass.IndexSchema.readSchema [collection1] Schema name=example
[junit4] 2> 12084 T23 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 12220 T23 oasr.RestManager$Registry.registerManagedResource Registered ManagedResource impl org.apache.solr.rest.schema.analysis.ManagedWordSetResource for path /schema/analysis/stopwords/english
[junit4] 2> 12228 T23 oasr.RestManager$Registry.registerManagedResource Registered ManagedResource impl org.apache.solr.rest.schema.analysis.ManagedSynonymFilterFactory$SynonymManager for path /schema/analysis/synonyms/english
[junit4] 2> 13117 T23 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 13131 T23 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 13450 T23 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/
[junit4] 2> 13619 T23 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 13687 T23 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/
[junit4] 2> 13700 T23 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 13753 T23 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 13754 T23 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
[junit4] 2> 13917 T23 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001
[junit4] 2> 13918 T23 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index/
[junit4] 2> 13920 T23 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index' doesn't exist. Creating new index...
[junit4] 2> 13949 T23 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index
[junit4] 2> 14168 T23 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-5-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@1299e361
[junit4] 2> 14174 T23 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-5-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 14174 T23 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-5-thread-1]: 0 msec to checkpoint
[junit4] 2> 14175 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: init: create=true
[junit4] 2> 14178 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]:
[junit4] 2> dir=MockDirectoryWrapper(RAMDirectory@71d7098 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index)
[junit4] 2> index=
[junit4] 2> version=5.0-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_5_0
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=CREATE
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene49
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@15dd43c8
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2> checkIntegrityAtMerge=false
[junit4] 2> writer=org.apache.lucene.util.SetOnce@287217d3
[junit4] 2>
[junit4] 2> 14181 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: now flush at shutdown
[junit4] 2> 14181 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 14183 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: index before flush
[junit4] 2> 14184 T23 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-5-thread-1]: startFullFlush
[junit4] 2> 14185 T23 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-5-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 14186 T23 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-5-thread-1]: coreLoadExecutor-5-thread-1 finishFullFlush success=true
[junit4] 2> 14188 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: apply all deletes during flush
[junit4] 2> 14193 T23 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-5-thread-1]: prune sis=null: minGen=9223372036854775807 packetCount=0
[junit4] 2> 14193 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: waitForMerges
[junit4] 2> 14194 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: waitForMerges done
[junit4] 2> 14194 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: commit: start
[junit4] 2> 14195 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: commit: enter lock
[junit4] 2> 14195 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: commit: now prepare
[junit4] 2> 14196 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: prepareCommit: flush
[junit4] 2> 14196 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: index before flush
[junit4] 2> 14196 T23 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-5-thread-1]: startFullFlush
[junit4] 2> 14196 T23 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-5-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 14197 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: apply all deletes during flush
[junit4] 2> 14197 T23 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-5-thread-1]: prune sis=null: minGen=9223372036854775807 packetCount=0
[junit4] 2> 14197 T23 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-5-thread-1]: coreLoadExecutor-5-thread-1 finishFullFlush success=true
[junit4] 2> 14198 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: startCommit(): start
[junit4] 2> 14198 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: startCommit index= changeCount=1
[junit4] 2> 14225 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: done all syncs: []
[junit4] 2> 14225 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: commit: pendingCommit != null
[junit4] 2> 14226 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: commit: wrote segments file "segments_1"
[junit4] 2> 14226 T23 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-5-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 14255 T23 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71d7098 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index),segFN=segments_1,generation=1}
[junit4] 2> 14262 T23 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 14263 T23 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-5-thread-1]: 36 msec to checkpoint
[junit4] 2> 14267 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: commit: took 68.2 msec
[junit4] 2> 14268 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: commit: done
[junit4] 2> 14268 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: rollback
[junit4] 2> 14269 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: all running merges have aborted
[junit4] 2> 14269 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: rollback: done finish merges
[junit4] 2> 14270 T23 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-5-thread-1]: abort
[junit4] 2> 14280 T23 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-5-thread-1]: done abort; abortedFiles=[] success=true
[junit4] 2> 14281 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: rollback: infos=
[junit4] 2> 14281 T23 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-5-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 14282 T23 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-5-thread-1]: 0 msec to checkpoint
[junit4] 2> 14331 T23 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 14332 T23 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
[junit4] 2> 14338 T23 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
[junit4] 2> 14383 T23 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
[junit4] 2> 14383 T23 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
[junit4] 2> 16057 T23 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 16183 T23 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 16184 T23 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
[junit4] 2> 16205 T23 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 16206 T23 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
[junit4] 2> 16246 T23 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 16246 T23 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.UpdateRequestHandler
[junit4] 2> 16247 T23 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.UpdateRequestHandler
[junit4] 2> 16247 T23 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
[junit4] 2> 16254 T23 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
[junit4] 2> 16255 T23 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[junit4] 2> 16255 T23 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
[junit4] 2> 16255 T23 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[junit4] 2> 16256 T23 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
[junit4] 2> 16286 T23 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 16313 T23 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 16350 T23 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 16421 T23 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 16422 T23 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 16422 T23 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
[junit4] 2> 16422 T23 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 16423 T23 oasc.RequestHandlers.initHandlersFromConfig created /suggest: solr.SearchHandler
[junit4] 2> 16423 T23 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 16423 T23 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
[junit4] 2> 16423 T23 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 16424 T23 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
[junit4] 2> 16424 T23 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 16425 T23 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
[junit4] 2> 16594 T23 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 16632 T23 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 16646 T23 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 16829 T23 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 16831 T23 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 16846 T23 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-5-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@1299e361
[junit4] 2> 16849 T23 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-5-thread-1]: init: load commit "segments_1"
[junit4] 2> 16849 T23 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71d7098 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index),segFN=segments_1,generation=1}
[junit4] 2> 16850 T23 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 16851 T23 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-5-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 16851 T23 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-5-thread-1]: 0 msec to checkpoint
[junit4] 2> 16851 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: init: create=false
[junit4] 2> 16852 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]:
[junit4] 2> dir=MockDirectoryWrapper(RAMDirectory@71d7098 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index)
[junit4] 2> index=
[junit4] 2> version=5.0-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_5_0
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=APPEND
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene49
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@26da252e
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2> checkIntegrityAtMerge=false
[junit4] 2> writer=org.apache.lucene.util.SetOnce@217173ec
[junit4] 2>
[junit4] 2> 16876 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: flush at getReader
[junit4] 2> 16876 T23 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-5-thread-1]: startFullFlush
[junit4] 2> 16877 T23 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-5-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 16877 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: apply all deletes during flush
[junit4] 2> 16877 T23 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-5-thread-1]: prune sis=segments_1: minGen=9223372036854775807 packetCount=0
[junit4] 2> 16893 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 16894 T23 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-5-thread-1]: coreLoadExecutor-5-thread-1 finishFullFlush success=true
[junit4] 2> 16894 T23 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-5-thread-1]: getReader took 18 msec
[junit4] 2> 16998 T23 oass.SolrIndexSearcher.<init> Opening Searcher@10036d23[collection1] main
[junit4] 2> 17099 T23 oasr.ManagedResourceStorage.newStorageIO WARN Cannot write to config directory /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/conf; switching to use InMemory storage instead.
[junit4] 2> 17110 T23 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 17121 T23 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 17123 T23 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 17135 T23 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using InMemoryStorage
[junit4] 2> 17137 T23 oasr.RestManager.init Initializing 2 registered ManagedResources
[junit4] 2> 17138 T23 oasr.ManagedResourceStorage.load Reading _schema_analysis_stopwords_english.json using InMemoryStorage
[junit4] 2> 17139 T23 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /schema/analysis/stopwords/english
[junit4] 2> 17168 T23 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _schema_analysis_stopwords_english.json using InMemoryStorage
[junit4] 2> 17172 T23 oasrsa.ManagedWordSetResource.onManagedDataLoadedFromStorage Loaded 0 words for /schema/analysis/stopwords/english
[junit4] 2> 17173 T23 oasr.ManagedResource.notifyObserversDuringInit Notified 1 observers of /schema/analysis/stopwords/english
[junit4] 2> 17175 T23 oasr.ManagedResourceStorage.load Reading _schema_analysis_synonyms_english.json using InMemoryStorage
[junit4] 2> 17176 T23 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /schema/analysis/synonyms/english
[junit4] 2> 17176 T23 oasrsa.ManagedSynonymFilterFactory$SynonymManager.onManagedDataLoadedFromStorage Loaded 0 synonym mappings for /schema/analysis/synonyms/english
[junit4] 2> 17185 T23 oasr.ManagedResource.notifyObserversDuringInit Notified 1 observers of /schema/analysis/synonyms/english
[junit4] 2> 17186 T23 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 17308 T23 oass.DirectSolrSpellChecker.init init: {name=default,field=text,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 17415 T23 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
[junit4] 2> 17424 T23 oashc.SuggestComponent.inform Initializing SuggestComponent
[junit4] 2> 17441 T23 oasss.SolrSuggester.init init: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
[junit4] 2> 17745 T23 oasss.SolrSuggester.init Dictionary loaded with params: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
[junit4] 2> 17763 T23 oashc.QueryElevationComponent.inform Loading QueryElevation from: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/example/solr/collection1/conf/elevate.xml
[junit4] 2> 18066 T23 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 18073 T23 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 18073 T24 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@10036d23[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 18086 T11 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0
[junit4] 2> 18087 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 18088 T11 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#53580
[junit4] 2> 18155 T11 oas.SolrTestCaseJ4.setUp ###Starting testUpdateField
[junit4] 2> ASYNC NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@344791dc
[junit4] 2> 18614 T24 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false&event=firstSearcher} hits=0 status=0 QTime=526
[junit4] 2> 18624 T24 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 18625 T24 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 18626 T24 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 18626 T24 oashc.SuggestComponent$SuggesterListener.newSearcher Loading suggester index for: mySuggester
[junit4] 2> 18627 T24 oasss.SolrSuggester.reload reload()
[junit4] 2> 18628 T24 oasss.SolrSuggester.build build()
[junit4] 2> 18780 T24 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10036d23[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> ASYNC NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@344791dc
[junit4] 2> 20227 T21 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-21]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20230 T21 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-21]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 20231 T21 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-21]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20232 T21 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-21]: flush at getReader
[junit4] 2> 20233 T21 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-21]: startFullFlush
[junit4] 2> 20234 T21 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-21]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20235 T21 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-21]: qtp1769747735-21: flush naked frozen global deletes
[junit4] 2> 20289 T21 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-21]: push deletes 1 deleted queries bytesUsed=64 delGen=2 packetCount=1 totBytesUsed=64
[junit4] 2> 20291 T21 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-21]: flush: push buffered updates: 1 deleted queries bytesUsed=64
[junit4] 2> 20291 T21 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-21]: apply all deletes during flush
[junit4] 2> 20292 T21 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-21]: prune sis=segments_1: minGen=9223372036854775807 packetCount=1
[junit4] 2> 20293 T21 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-21]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 20294 T21 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-21]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 20294 T21 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-21]: qtp1769747735-21 finishFullFlush success=true
[junit4] 2> 20295 T21 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-21]: getReader took 63 msec
[junit4] 2> 20310 T21 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1472758989717504000)} 0 626
[junit4] 2> 20490 T17 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 20492 T17 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-17]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20493 T17 C1 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 20494 T17 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-17]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20494 T17 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 20495 T17 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-17]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20495 T17 C1 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 20498 T17 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 20498 T17 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} {commit=} 0 8
[junit4] 2> 20905 T15 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[unique (1472758990169440256)]} 0 393
[junit4] 2> 20911 T19 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 20913 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: commit: start
[junit4] 2> 20914 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: commit: enter lock
[junit4] 2> 20914 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: commit: now prepare
[junit4] 2> 20915 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: prepareCommit: flush
[junit4] 2> 20916 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: index before flush
[junit4] 2> 20916 T19 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-19]: startFullFlush
[junit4] 2> 20917 T19 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-19]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20918 T19 C1 oasu.LoggingInfoStream.message [DWFC][qtp1769747735-19]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_0, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 2 ]]
[junit4] 2> 20930 T19 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-19]: flush postings as segment _0 numDocs=1
[junit4] 2> 21144 T19 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-19]: new segment has 0 deleted docs
[junit4] 2> 21144 T19 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-19]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 21146 T19 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-19]: flushedFiles=[_0_Lucene41_0.tip, _0_Lucene41_0.doc, _0_Lucene41_0.tim, _0.nvd, _0.fdx, _0.fdt, _0_Lucene41_0.pos, _0.nvm, _0.fnm]
[junit4] 2> 21150 T19 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-19]: flushed codec=Lucene49
[junit4] 2> 21159 T19 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-19]: flushed: segment=_0 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=757.642
[junit4] 2> 21175 T19 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-19]: publishFlushedSegment seg-private updates=null
[junit4] 2> 21177 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: publishFlushedSegment
[junit4] 2> 21177 T19 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-19]: push deletes 1 deleted terms (unique count=1) bytesUsed=1056 delGen=4 packetCount=1 totBytesUsed=1056
[junit4] 2> 21177 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: publish sets newSegment delGen=5 seg=_0(5.0):C1
[junit4] 2> 21178 T19 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-19]: now checkpoint "_0(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 21179 T19 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-19]: 0 msec to checkpoint
[junit4] 2> 21179 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: apply all deletes during flush
[junit4] 2> 21179 T19 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-19]: applyDeletes: infos=[_0(5.0):C1] packetCount=1
[junit4] 2> 21180 T19 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-19]: applyDeletes took 1 msec
[junit4] 2> 21180 T19 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-19]: prune sis=segments_1: _0(5.0):C1 minGen=6 packetCount=1
[junit4] 2> 21181 T19 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-19]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 21182 T19 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-19]: qtp1769747735-19 finishFullFlush success=true
[junit4] 2> 21188 T19 C1 oasu.LoggingInfoStream.message [TMP][qtp1769747735-19]: findMerges: 1 segments
[junit4] 2> 21194 T19 C1 oasu.LoggingInfoStream.message [TMP][qtp1769747735-19]: seg=_0(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 21195 T19 C1 oasu.LoggingInfoStream.message [TMP][qtp1769747735-19]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 21195 T19 C1 oasu.LoggingInfoStream.message [CMS][qtp1769747735-19]: now merge
[junit4] 2> 21196 T19 C1 oasu.LoggingInfoStream.message [CMS][qtp1769747735-19]: index: _0(5.0):C1
[junit4] 2> 21196 T19 C1 oasu.LoggingInfoStream.message [CMS][qtp1769747735-19]: no more merges pending; now return
[junit4] 2> 21196 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: startCommit(): start
[junit4] 2> 21197 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: startCommit index=_0(5.0):C1 changeCount=3
[junit4] 2> 21203 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: done all syncs: [_0_Lucene41_0.tip, _0_Lucene41_0.doc, _0.si, _0_Lucene41_0.tim, _0.nvd, _0.fdx, _0.fdt, _0_Lucene41_0.pos, _0.nvm, _0.fnm]
[junit4] 2> 21204 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: commit: pendingCommit != null
[junit4] 2> 21204 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: commit: wrote segments file "segments_2"
[junit4] 2> 21205 T19 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-19]: now checkpoint "_0(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 21205 T19 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71d7098 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71d7098 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index),segFN=segments_2,generation=2}
[junit4] 2> 21208 T19 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 21208 T19 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-19]: deleteCommits: now decRef commit "segments_1"
[junit4] 2> 21208 T19 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-19]: delete "segments_1"
[junit4] 2> 21209 T19 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-19]: 4 msec to checkpoint
[junit4] 2> 21210 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: commit: took 295.0 msec
[junit4] 2> 21210 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: commit: done
[junit4] 2> 21211 T19 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-19]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 21211 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 21211 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: flush at getReader
[junit4] 2> 21212 T19 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-19]: startFullFlush
[junit4] 2> 21212 T19 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-19]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 21213 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: apply all deletes during flush
[junit4] 2> 21213 T19 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-19]: applyDeletes: no deletes; skipping
[junit4] 2> 21214 T19 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-19]: prune sis=segments_2: _0(5.0):C1 minGen=6 packetCount=0
[junit4] 2> 21349 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)
[junit4] 2> 21350 T19 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-19]: qtp1769747735-19 finishFullFlush success=true
[junit4] 2> 21351 T19 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-19]: getReader took 140 msec
[junit4] 2> 21357 T19 C1 oass.SolrIndexSearcher.<init> Opening Searcher@161deb49[collection1] main
[junit4] 2> 21379 T19 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 21379 T24 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@161deb49[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C1))}
[junit4] 2> 21381 T24 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 21381 T24 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@161deb49[collection1] main{UninvertingDirectoryReader(Uninverting(_0(5.0):C1))}
[junit4] 2> 21383 T19 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} {commit=} 0 472
[junit4] 2> 21552 T21 C1 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&fl=id,price_f,name,_version_&wt=javabin&version=2} hits=1 status=0 QTime=110
[junit4] 2> 21808 T17 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {} 0 236
[junit4] 2> 21824 T22 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[unique (1472758991532589056)]} 0 6
[junit4] 2> 21831 T18 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 21831 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: commit: start
[junit4] 2> 21832 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: commit: enter lock
[junit4] 2> 21832 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: commit: now prepare
[junit4] 2> 21832 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: prepareCommit: flush
[junit4] 2> 21834 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: index before flush _0(5.0):C1
[junit4] 2> 21834 T18 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-18]: startFullFlush
[junit4] 2> 21835 T18 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-18]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 21836 T18 C1 oasu.LoggingInfoStream.message [DWFC][qtp1769747735-18]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_1, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 4 ]]
[junit4] 2> 21836 T18 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-18]: flush postings as segment _1 numDocs=1
[junit4] 2> 21841 T18 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-18]: new segment has 0 deleted docs
[junit4] 2> 21842 T18 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-18]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 21842 T18 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-18]: flushedFiles=[_1.nvd, _1_Lucene41_0.tip, _1.fdx, _1_Lucene41_0.doc, _1_Lucene41_0.tim, _1.nvm, _1.fnm, _1.fdt, _1_Lucene41_0.pos]
[junit4] 2> 21842 T18 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-18]: flushed codec=Lucene49
[junit4] 2> 21843 T18 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-18]: flushed: segment=_1 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=757.642
[junit4] 2> 21844 T18 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-18]: publishFlushedSegment seg-private updates=null
[junit4] 2> 21845 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: publishFlushedSegment
[junit4] 2> 21845 T18 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-18]: push deletes 1 deleted terms (unique count=1) bytesUsed=1056 delGen=8 packetCount=1 totBytesUsed=1056
[junit4] 2> 21845 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: publish sets newSegment delGen=9 seg=_1(5.0):C1
[junit4] 2> 21846 T18 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-18]: now checkpoint "_0(5.0):C1 _1(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 21847 T18 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-18]: 1 msec to checkpoint
[junit4] 2> 21848 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: apply all deletes during flush
[junit4] 2> 21849 T18 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-18]: applyDeletes: infos=[_0(5.0):C1, _1(5.0):C1] packetCount=1
[junit4] 2> 21981 T18 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-18]: seg=_0(5.0):C1 segGen=6 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=1 100% deleted
[junit4] 2> 21983 T18 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-18]: applyDeletes took 134 msec
[junit4] 2> 21983 T18 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-18]: now checkpoint "_0(5.0):C1/1 _1(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 21984 T18 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-18]: 0 msec to checkpoint
[junit4] 2> 21984 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: drop 100% deleted segments: _0(5.0):C1/1
[junit4] 2> 21984 T18 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-18]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 21986 T18 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-18]: 1 msec to checkpoint
[junit4] 2> 21986 T18 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-18]: prune sis=segments_2: _1(5.0):C1 minGen=10 packetCount=1
[junit4] 2> 21986 T18 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-18]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 21989 T18 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-18]: qtp1769747735-18 finishFullFlush success=true
[junit4] 2> 21990 T18 C1 oasu.LoggingInfoStream.message [TMP][qtp1769747735-18]: findMerges: 1 segments
[junit4] 2> 21991 T18 C1 oasu.LoggingInfoStream.message [TMP][qtp1769747735-18]: seg=_1(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 21992 T18 C1 oasu.LoggingInfoStream.message [TMP][qtp1769747735-18]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 21993 T18 C1 oasu.LoggingInfoStream.message [CMS][qtp1769747735-18]: now merge
[junit4] 2> 21993 T18 C1 oasu.LoggingInfoStream.message [CMS][qtp1769747735-18]: index: _1(5.0):C1
[junit4] 2> 21994 T18 C1 oasu.LoggingInfoStream.message [CMS][qtp1769747735-18]: no more merges pending; now return
[junit4] 2> 21994 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: startCommit(): start
[junit4] 2> 21994 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: startCommit index=_1(5.0):C1 changeCount=8
[junit4] 2> 21996 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: done all syncs: [_1.si, _1.nvd, _1_Lucene41_0.tip, _1.fdx, _1_Lucene41_0.doc, _1_Lucene41_0.tim, _1.nvm, _1.fnm, _1.fdt, _1_Lucene41_0.pos]
[junit4] 2> 21996 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: commit: pendingCommit != null
[junit4] 2> 21998 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: commit: wrote segments file "segments_3"
[junit4] 2> 21998 T18 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-18]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 21999 T18 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71d7098 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71d7098 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index),segFN=segments_3,generation=3}
[junit4] 2> 21999 T18 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 22000 T18 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-18]: deleteCommits: now decRef commit "segments_2"
[junit4] 2> 22000 T18 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-18]: delete "segments_2"
[junit4] 2> 22003 T18 C1 oasu.LoggingInfoStream.message [IFD][qtp1769747735-18]: 5 msec to checkpoint
[junit4] 2> 22004 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: commit: took 171.6 msec
[junit4] 2> 22004 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: commit: done
[junit4] 2> 22005 T18 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-18]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 22005 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 22006 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: flush at getReader
[junit4] 2> 22006 T18 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-18]: startFullFlush
[junit4] 2> 22007 T18 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-18]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 22007 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: apply all deletes during flush
[junit4] 2> 22008 T18 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-18]: applyDeletes: no deletes; skipping
[junit4] 2> 22008 T18 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-18]: prune sis=segments_3: _1(5.0):C1 minGen=10 packetCount=0
[junit4] 2> 22014 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: return reader version=7 reader=StandardDirectoryReader(segments_3:7:nrt _1(5.0):C1)
[junit4] 2> 22015 T18 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-18]: qtp1769747735-18 finishFullFlush success=true
[junit4] 2> 22016 T18 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-18]: getReader took 10 msec
[junit4] 2> 22016 T18 C1 oass.SolrIndexSearcher.<init> Opening Searcher@5c4a4b3e[collection1] main
[junit4] 2> 22021 T18 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 22021 T24 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5c4a4b3e[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C1))}
[junit4] 2> 22021 T24 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 22022 T24 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c4a4b3e[collection1] main{UninvertingDirectoryReader(Uninverting(_1(5.0):C1))}
[junit4] 2> 22024 T24 oasu.LoggingInfoStream.message [IFD][searcherExecutor-6-thread-1]: delete "_0_Lucene41_0.tip"
[junit4] 2> 22027 T24 oasu.LoggingInfoStream.message [IFD][searcherExecutor-6-thread-1]: delete "_0_Lucene41_0.doc"
[junit4] 2> 22027 T24 oasu.LoggingInfoStream.message [IFD][searcherExecutor-6-thread-1]: delete "_0.si"
[junit4] 2> 22028 T24 oasu.LoggingInfoStream.message [IFD][searcherExecutor-6-thread-1]: delete "_0_Lucene41_0.tim"
[junit4] 2> 22028 T24 oasu.LoggingInfoStream.message [IFD][searcherExecutor-6-thread-1]: delete "_0.nvd"
[junit4] 2> 22031 T24 oasu.LoggingInfoStream.message [IFD][searcherExecutor-6-thread-1]: delete "_0.fdx"
[junit4] 2> 22032 T24 oasu.LoggingInfoStream.message [IFD][searcherExecutor-6-thread-1]: delete "_0.fdt"
[junit4] 2> 22032 T24 oasu.LoggingInfoStream.message [IFD][searcherExecutor-6-thread-1]: delete "_0_Lucene41_0.pos"
[junit4] 2> 22032 T24 oasu.LoggingInfoStream.message [IFD][searcherExecutor-6-thread-1]: delete "_0.nvm"
[junit4] 2> 22032 T24 oasu.LoggingInfoStream.message [IFD][searcherExecutor-6-thread-1]: delete "_0.fnm"
[junit4] 2> 22033 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} {commit=} 0 202
[junit4] 2> 22041 T19 C1 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&fl=id,price_f,name,_version_&wt=javabin&version=2} hits=1 status=0 QTime=2
[junit4] 2> 22051 T21 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[unique (1472758991771664384)]} 0 4
[junit4] 2> 22059 T17 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 22060 T17 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: commit: start
[junit4] 2> 22061 T17 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: commit: enter lock
[junit4] 2> 22061 T17 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: commit: now prepare
[junit4] 2> 22062 T17 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: prepareCommit: flush
[junit4] 2> 22065 T17 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: index before flush _1(5.0):C1
[junit4] 2> 22065 T17 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-17]: startFullFlush
[junit4] 2> 22066 T17 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-17]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 22066 T17 C1 oasu.LoggingInfoStream.message [DWFC][qtp1769747735-17]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_2, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 6 ]]
[junit4] 2> 22067 T17 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-17]: flush postings as segment _2 numDocs=1
[junit4] 2> 22074 T17 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-17]: new segment has 0 deleted docs
[junit4] 2> 22076 T17 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-17]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 22076 T17 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-17]: flushedFiles=[_2.nvd, _2_Lucene41_0.tip, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tim, _2.nvm, _2.fnm, _2.fdx, _2_Lucene41_0.pos]
[junit4] 2> 22077 T17 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-17]: flushed codec=Lucene49
[junit4] 2> 22079 T17 C1 oasu.LoggingInfoStream.message [DWPT][qtp1769747735-17]: flushed: segment=_2 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=757.642
[junit4] 2> 22083 T17 C1 oasu.LoggingInfoStream.message [DW][qtp1769747735-17]: publishFlushedSegment seg-private updates=null
[junit4] 2> 22086 T17 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: publishFlushedSegment
[junit4] 2> 22087 T17 C1 oasu.LoggingInfoStream.message [BD][qtp1769747735-17]: push deletes 1 deleted terms (unique count=1) bytesUsed=1056 delGen=12 packetCount=1 totBytesUsed=1056
[junit4] 2> 22097 T17 C1 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: publish sets newSegment delGen=13 seg=_2(5.0):C1
[junit4] 2> ASYNC NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@344791dc
[junit4] 2> 22125 T17 C2 oasu.LoggingInfoStream.message [IFD][qtp1769747735-17]: now checkpoint "_1(5.0):C1 _2(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 22129 T17 C2 oasu.LoggingInfoStream.message [IFD][qtp1769747735-17]: 4 msec to checkpoint
[junit4] 2> 22130 T17 C2 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: apply all deletes during flush
[junit4] 2> 22131 T17 C2 oasu.LoggingInfoStream.message [BD][qtp1769747735-17]: applyDeletes: infos=[_1(5.0):C1, _2(5.0):C1] packetCount=1
[junit4] 2> 22132 T17 C2 oasu.LoggingInfoStream.message [BD][qtp1769747735-17]: seg=_1(5.0):C1 segGen=10 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericDVUpdates=0,binaryDVUpdates=0)] newDelCount=1 100% deleted
[junit4] 2> 22132 T17 C2 oasu.LoggingInfoStream.message [BD][qtp1769747735-17]: applyDeletes took 1 msec
[junit4] 2> 22133 T17 C2 oasu.LoggingInfoStream.message [IFD][qtp1769747735-17]: now checkpoint "_1(5.0):C1/1 _2(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 22133 T17 C2 oasu.LoggingInfoStream.message [IFD][qtp1769747735-17]: 0 msec to checkpoint
[junit4] 2> 22134 T17 C2 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: drop 100% deleted segments: _1(5.0):C1/1
[junit4] 2> 22135 T17 C2 oasu.LoggingInfoStream.message [IFD][qtp1769747735-17]: now checkpoint "_2(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 22136 T17 C2 oasu.LoggingInfoStream.message [IFD][qtp1769747735-17]: 0 msec to checkpoint
[junit4] 2> 22136 T17 C2 oasu.LoggingInfoStream.message [BD][qtp1769747735-17]: prune sis=segments_3: _2(5.0):C1 minGen=14 packetCount=1
[junit4] 2> 22137 T17 C2 oasu.LoggingInfoStream.message [BD][qtp1769747735-17]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 22138 T17 C2 oasu.LoggingInfoStream.message [DW][qtp1769747735-17]: qtp1769747735-17 finishFullFlush success=true
[junit4] 2> 22138 T17 C2 oasu.LoggingInfoStream.message [TMP][qtp1769747735-17]: findMerges: 1 segments
[junit4] 2> 22144 T17 C2 oasu.LoggingInfoStream.message [TMP][qtp1769747735-17]: seg=_2(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 22144 T17 C2 oasu.LoggingInfoStream.message [TMP][qtp1769747735-17]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 22145 T17 C2 oasu.LoggingInfoStream.message [CMS][qtp1769747735-17]: now merge
[junit4] 2> 22145 T17 C2 oasu.LoggingInfoStream.message [CMS][qtp1769747735-17]: index: _2(5.0):C1
[junit4] 2> 22146 T17 C2 oasu.LoggingInfoStream.message [CMS][qtp1769747735-17]: no more merges pending; now return
[junit4] 2> 22146 T17 C2 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: startCommit(): start
[junit4] 2> 22146 T17 C2 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: startCommit index=_2(5.0):C1 changeCount=13
[junit4] 2> 22148 T17 C2 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: done all syncs: [_2.nvd, _2.si, _2_Lucene41_0.tip, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tim, _2.nvm, _2.fnm, _2.fdx, _2_Lucene41_0.pos]
[junit4] 2> 22148 T17 C2 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: commit: pendingCommit != null
[junit4] 2> 22149 T17 C2 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: commit: wrote segments file "segments_4"
[junit4] 2> 22149 T17 C2 oasu.LoggingInfoStream.message [IFD][qtp1769747735-17]: now checkpoint "_2(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 22149 T17 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71d7098 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71d7098 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleJettyTest-EAE765ED855F3E3F-001/tempDir-001/index),segFN=segments_4,generation=4}
[junit4] 2> 22150 T17 C2 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 22151 T17 C2 oasu.LoggingInfoStream.message [IFD][qtp1769747735-17]: deleteCommits: now decRef commit "segments_3"
[junit4] 2> 22152 T17 C2 oasu.LoggingInfoStream.message [IFD][qtp1769747735-17]: delete "segments_3"
[junit4] 2> 22152 T17 C2 oasu.LoggingInfoStream.message [IFD][qtp1769747735-17]: 3 msec to checkpoint
[junit4] 2> 22153 T17 C2 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: commit: took 90.1 msec
[junit4] 2> 22153 T17 C2 oasu.LoggingInfoStream.message [IW][qtp1769747735-17]: commit: done
[junit4] 2> 221
[...truncated too long message...]
]]: flush at getReader
[junit4] 2> 183159 T557 C68 oasu.LoggingInfoStream.message [DW][TEST-SolrExampleEmbeddedTest.testMultiContentStreamRequest-seed#[EAE765ED855F3E3F]]: startFullFlush
[junit4] 2> 183159 T557 C68 oasu.LoggingInfoStream.message [DW][TEST-SolrExampleEmbeddedTest.testMultiContentStreamRequest-seed#[EAE765ED855F3E3F]]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 183159 T557 C68 oasu.LoggingInfoStream.message [IW][TEST-SolrExampleEmbeddedTest.testMultiContentStreamRequest-seed#[EAE765ED855F3E3F]]: apply all deletes during flush
[junit4] 2> 183160 T557 C68 oasu.LoggingInfoStream.message [BD][TEST-SolrExampleEmbeddedTest.testMultiContentStreamRequest-seed#[EAE765ED855F3E3F]]: applyDeletes: no deletes; skipping
[junit4] 2> 183160 T557 C68 oasu.LoggingInfoStream.message [BD][TEST-SolrExampleEmbeddedTest.testMultiContentStreamRequest-seed#[EAE765ED855F3E3F]]: prune sis=segments_1n: _15(5.0):C5 minGen=246 packetCount=0
[junit4] 2> 183161 T557 C68 oasu.LoggingInfoStream.message [IW][TEST-SolrExampleEmbeddedTest.testMultiContentStreamRequest-seed#[EAE765ED855F3E3F]]: return reader version=155 reader=StandardDirectoryReader(segments_1n:155:nrt _15(5.0):C5)
[junit4] 2> 183162 T557 C68 oasu.LoggingInfoStream.message [DW][TEST-SolrExampleEmbeddedTest.testMultiContentStreamRequest-seed#[EAE765ED855F3E3F]]: TEST-SolrExampleEmbeddedTest.testMultiContentStreamRequest-seed#[EAE765ED855F3E3F] finishFullFlush success=true
[junit4] 2> 183163 T557 C68 oasu.LoggingInfoStream.message [IW][TEST-SolrExampleEmbeddedTest.testMultiContentStreamRequest-seed#[EAE765ED855F3E3F]]: getReader took 5 msec
[junit4] 2> 183163 T557 C68 oass.SolrIndexSearcher.<init> Opening Searcher@7f1e3d03[collection1] main
[junit4] 2> 183164 T559 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7f1e3d03[collection1] main{UninvertingDirectoryReader(Uninverting(_15(5.0):C5))}
[junit4] 2> 183165 T559 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 183165 T557 C68 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 183166 T559 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7f1e3d03[collection1] main{UninvertingDirectoryReader(Uninverting(_15(5.0):C5))}
[junit4] 2> 183167 T557 C68 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={a=%E1%88%B4&echoParams=ALL&commit=true&softCommit=false&waitSearcher=true} {add=[SP2514N (1472759160421482496), 6H500F0 (1472759160424628224), TWINX2048-3200PRO (1472759160425676800), VS1GB400C3 (1472759160426725376), VDBDB1A16 (1472759160428822528)],commit=} 0 283
[junit4] 2> 183168 T557 C68 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*} hits=5 status=0 QTime=1
[junit4] 2> 183169 T557 oas.SolrTestCaseJ4.tearDown ###Ending testMultiContentStreamRequest
[junit4] 2> 183170 T557 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=445746363
[junit4] 2> 183171 T557 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@61cac3ab
[junit4] 2> 183193 T557 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=62,autocommit maxTime=15000ms,autocommits=0,soft autocommits=3,optimizes=2,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=1,cumulative_adds=192,cumulative_deletesById=5,cumulative_deletesByQuery=29,cumulative_errors=1,transaction_logs_total_size=3808,transaction_logs_total_number=10}
[junit4] 2> 183195 T557 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 183195 T557 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 183195 T557 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 183199 T557 C68 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleEmbeddedTest-seed#[EAE765ED855F3E3F]-worker]: waitForMerges
[junit4] 2> 183199 T557 C68 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleEmbeddedTest-seed#[EAE765ED855F3E3F]-worker]: waitForMerges done
[junit4] 2> 183199 T557 C68 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleEmbeddedTest-seed#[EAE765ED855F3E3F]-worker]: rollback
[junit4] 2> 183200 T557 C68 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleEmbeddedTest-seed#[EAE765ED855F3E3F]-worker]: all running merges have aborted
[junit4] 2> 183200 T557 C68 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleEmbeddedTest-seed#[EAE765ED855F3E3F]-worker]: rollback: done finish merges
[junit4] 2> 183200 T557 C68 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleEmbeddedTest-seed#[EAE765ED855F3E3F]-worker]: abort
[junit4] 2> 183200 T557 C68 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleEmbeddedTest-seed#[EAE765ED855F3E3F]-worker]: done abort; abortedFiles=[] success=true
[junit4] 2> 183201 T557 C68 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleEmbeddedTest-seed#[EAE765ED855F3E3F]-worker]: rollback: infos=_15(5.0):C5
[junit4] 2> 183201 T557 C68 oasu.LoggingInfoStream.message [IFD][SUITE-SolrExampleEmbeddedTest-seed#[EAE765ED855F3E3F]-worker]: now checkpoint "_15(5.0):C5" [1 segments ; isCommit = false]
[junit4] 2> 183202 T557 C68 oasu.LoggingInfoStream.message [IFD][SUITE-SolrExampleEmbeddedTest-seed#[EAE765ED855F3E3F]-worker]: 0 msec to checkpoint
[junit4] 2> 183206 T557 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 183207 T557 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 183207 T557 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/./temp/solr.client.solrj.embedded.SolrExampleEmbeddedTest-EAE765ED855F3E3F-001/init-core-data-001/index [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/./temp/solr.client.solrj.embedded.SolrExampleEmbeddedTest-EAE765ED855F3E3F-001/init-core-data-001/index;done=false>>]
[junit4] 2> 183207 T557 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/./temp/solr.client.solrj.embedded.SolrExampleEmbeddedTest-EAE765ED855F3E3F-001/init-core-data-001/index
[junit4] 2> 183207 T557 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/./temp/solr.client.solrj.embedded.SolrExampleEmbeddedTest-EAE765ED855F3E3F-001/init-core-data-001 [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/./temp/solr.client.solrj.embedded.SolrExampleEmbeddedTest-EAE765ED855F3E3F-001/init-core-data-001;done=false>>]
[junit4] 2> 183208 T557 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/./temp/solr.client.solrj.embedded.SolrExampleEmbeddedTest-EAE765ED855F3E3F-001/init-core-data-001
[junit4] 2> 183208 T557 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 183208 T557 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=445746363
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/test/J0/./temp/solr.client.solrj.embedded.SolrExampleEmbeddedTest-EAE765ED855F3E3F-001
[junit4] 2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=cs, timezone=Asia/Dili
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_05 (64-bit)/cpus=2,threads=1,free=165758496,total=202375168
[junit4] 2> NOTE: All tests run in this JVM: [SolrExampleJettyTest, TestBatchUpdate, MergeIndexesEmbeddedTest, BasicHttpSolrServerTest, TestSpellCheckResponse, TestEmbeddedSolrServer, SolrExampleStreamingBinaryTest, TestRetryUtil, LargeVolumeJettyTest, TestLBHttpSolrServer, AnlysisResponseBaseTest, TestDocumentObjectBinder, TestHash, SolrDocumentTest, TestNamedListCodec, ModifiableSolrParamsTest, ContentStreamTest, SolrExampleXMLTest, TestFastInputStream, SolrExampleBinaryTest, NamedListTest, SolrParamTest, JettyWebappTest, CloudSolrServerTest, SolrExampleStreamingTest, SolrExampleEmbeddedTest]
[junit4] Completed in 8.08s, 27 tests, 1 failure <<< FAILURES!
[...truncated 75 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:202: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1298: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:922: There were test failures: 49 suites, 295 tests, 3 errors, 1 failure
Total time: 105 minutes 2 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any